From 5d2326389872566f018b730ff47ba72de04e3e9d Mon Sep 17 00:00:00 2001 From: Jordan Wright Date: Thu, 3 May 2018 19:07:41 -0500 Subject: [PATCH] Moved logging to logrus package. Not perfect yet (still want to update the access logs), but should set the foundation to make better logging in the future. --- auth/auth.go | 3 +- config/config.go | 5 +- controllers/api.go | 46 ++++++++------- controllers/phish.go | 31 +++++----- controllers/route.go | 20 +++---- gophish.go | 33 ++++++----- logger/doc.go | 29 ++++++++++ logger/logger.go | 65 +++++++++++++++++++++ mailer/mailer.go | 29 ++++++++-- models/campaign.go | 121 +++++++++++++++++++++++----------------- models/email_request.go | 11 ++-- models/group.go | 56 ++++++++++++------- models/maillog.go | 19 ++++--- models/models.go | 18 +++--- models/page.go | 15 ++--- models/result.go | 4 +- models/smtp.go | 35 ++++++------ models/template.go | 30 +++++----- util/util.go | 9 +-- worker/worker.go | 23 ++++---- 20 files changed, 373 insertions(+), 229 deletions(-) create mode 100644 logger/doc.go create mode 100644 logger/logger.go diff --git a/auth/auth.go b/auth/auth.go index e371b3a4..0514d14e 100644 --- a/auth/auth.go +++ b/auth/auth.go @@ -10,6 +10,7 @@ import ( "crypto/rand" ctx "github.com/gophish/gophish/context" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/models" "github.com/gorilla/securecookie" "github.com/gorilla/sessions" @@ -73,7 +74,7 @@ func Register(r *http.Request) (bool, error) { // If we have an error which is not simply indicating that no user was found, report it if err != nil && err != gorm.ErrRecordNotFound { - fmt.Println(err) + log.Warn(err) return false, err } diff --git a/config/config.go b/config/config.go index bebc2ca7..62d0c184 100644 --- a/config/config.go +++ b/config/config.go @@ -2,8 +2,9 @@ package config import ( "encoding/json" - "fmt" "io/ioutil" + + log "github.com/gophish/gophish/logger" ) // AdminServer represents the Admin server configuration details @@ -43,7 +44,7 @@ func LoadConfig(filepath string) { // Get the config file configFile, err := ioutil.ReadFile(filepath) if err != nil { - fmt.Printf("File error: %v\n", err) + log.Errorf("File error: %v\n", err) } json.Unmarshal(configFile, &Conf) diff --git a/controllers/api.go b/controllers/api.go index c3409a3a..ca99f369 100644 --- a/controllers/api.go +++ b/controllers/api.go @@ -15,12 +15,14 @@ import ( "github.com/PuerkitoBio/goquery" "github.com/gophish/gophish/auth" ctx "github.com/gophish/gophish/context" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/models" "github.com/gophish/gophish/util" "github.com/gophish/gophish/worker" "github.com/gorilla/mux" "github.com/jinzhu/gorm" "github.com/jordan-wright/email" + "github.com/sirupsen/logrus" ) // Worker is the worker that processes phishing events and updates campaigns. @@ -38,7 +40,7 @@ func API(w http.ResponseWriter, r *http.Request) { templates := template.New("template") _, err := templates.ParseFiles("templates/docs.html") if err != nil { - Logger.Println(err) + log.Error(err) } template.Must(templates, err).ExecuteTemplate(w, "base", nil) } @@ -66,7 +68,7 @@ func API_Campaigns(w http.ResponseWriter, r *http.Request) { case r.Method == "GET": cs, err := models.GetCampaigns(ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) } JSONResponse(w, cs, http.StatusOK) //POST: Create a new campaign and return it as JSON @@ -98,7 +100,7 @@ func API_Campaigns_Summary(w http.ResponseWriter, r *http.Request) { case r.Method == "GET": cs, err := models.GetCampaignSummaries(ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) JSONResponse(w, models.Response{Success: false, Message: err.Error()}, http.StatusInternalServerError) return } @@ -113,7 +115,7 @@ func API_Campaigns_Id(w http.ResponseWriter, r *http.Request) { id, _ := strconv.ParseInt(vars["id"], 0, 64) c, err := models.GetCampaign(id, ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) JSONResponse(w, models.Response{Success: false, Message: "Campaign not found"}, http.StatusNotFound) return } @@ -137,7 +139,7 @@ func API_Campaigns_Id_Results(w http.ResponseWriter, r *http.Request) { id, _ := strconv.ParseInt(vars["id"], 0, 64) cr, err := models.GetCampaignResults(id, ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) JSONResponse(w, models.Response{Success: false, Message: "Campaign not found"}, http.StatusNotFound) return } @@ -160,7 +162,7 @@ func API_Campaign_Id_Summary(w http.ResponseWriter, r *http.Request) { } else { JSONResponse(w, models.Response{Success: false, Message: err.Error()}, http.StatusInternalServerError) } - Logger.Println(err) + log.Error(err) return } JSONResponse(w, cs, http.StatusOK) @@ -225,7 +227,7 @@ func API_Groups_Summary(w http.ResponseWriter, r *http.Request) { case r.Method == "GET": gs, err := models.GetGroupSummaries(ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) JSONResponse(w, models.Response{Success: false, Message: err.Error()}, http.StatusInternalServerError) return } @@ -293,7 +295,7 @@ func API_Templates(w http.ResponseWriter, r *http.Request) { case r.Method == "GET": ts, err := models.GetTemplates(ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) } JSONResponse(w, ts, http.StatusOK) //POST: Create a new template and return it as JSON @@ -323,7 +325,7 @@ func API_Templates(w http.ResponseWriter, r *http.Request) { } if err != nil { JSONResponse(w, models.Response{Success: false, Message: "Error inserting template into database"}, http.StatusInternalServerError) - Logger.Println(err) + log.Error(err) return } JSONResponse(w, t, http.StatusCreated) @@ -353,7 +355,7 @@ func API_Templates_Id(w http.ResponseWriter, r *http.Request) { t = models.Template{} err = json.NewDecoder(r.Body).Decode(&t) if err != nil { - Logger.Println(err) + log.Error(err) } if t.Id != id { JSONResponse(w, models.Response{Success: false, Message: "Error: /:id and template_id mismatch"}, http.StatusBadRequest) @@ -376,7 +378,7 @@ func API_Pages(w http.ResponseWriter, r *http.Request) { case r.Method == "GET": ps, err := models.GetPages(ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) } JSONResponse(w, ps, http.StatusOK) //POST: Create a new page and return it as JSON @@ -392,7 +394,7 @@ func API_Pages(w http.ResponseWriter, r *http.Request) { _, err = models.GetPageByName(p.Name, ctx.Get(r, "user_id").(int64)) if err != gorm.ErrRecordNotFound { JSONResponse(w, models.Response{Success: false, Message: "Page name already in use"}, http.StatusConflict) - Logger.Println(err) + log.Error(err) return } p.ModifiedDate = time.Now().UTC() @@ -430,7 +432,7 @@ func API_Pages_Id(w http.ResponseWriter, r *http.Request) { p = models.Page{} err = json.NewDecoder(r.Body).Decode(&p) if err != nil { - Logger.Println(err) + log.Error(err) } if p.Id != id { JSONResponse(w, models.Response{Success: false, Message: "/:id and /:page_id mismatch"}, http.StatusBadRequest) @@ -453,7 +455,7 @@ func API_SMTP(w http.ResponseWriter, r *http.Request) { case r.Method == "GET": ss, err := models.GetSMTPs(ctx.Get(r, "user_id").(int64)) if err != nil { - Logger.Println(err) + log.Error(err) } JSONResponse(w, ss, http.StatusOK) //POST: Create a new SMTP and return it as JSON @@ -469,7 +471,7 @@ func API_SMTP(w http.ResponseWriter, r *http.Request) { _, err = models.GetSMTPByName(s.Name, ctx.Get(r, "user_id").(int64)) if err != gorm.ErrRecordNotFound { JSONResponse(w, models.Response{Success: false, Message: "SMTP name already in use"}, http.StatusConflict) - Logger.Println(err) + log.Error(err) return } s.ModifiedDate = time.Now().UTC() @@ -507,7 +509,7 @@ func API_SMTP_Id(w http.ResponseWriter, r *http.Request) { s = models.SMTP{} err = json.NewDecoder(r.Body).Decode(&s) if err != nil { - Logger.Println(err) + log.Error(err) } if s.Id != id { JSONResponse(w, models.Response{Success: false, Message: "/:id and /:smtp_id mismatch"}, http.StatusBadRequest) @@ -558,7 +560,7 @@ func API_Import_Email(w http.ResponseWriter, r *http.Request) { } e, err := email.NewEmailFromReader(strings.NewReader(ir.Content)) if err != nil { - Logger.Println(err) + log.Error(err) } // If the user wants to convert links to point to // the landing page, let's make it happen by changing up @@ -688,11 +690,13 @@ func API_Send_Test_Email(w http.ResponseWriter, r *http.Request) { // Get the Template requested by name s.Template, err = models.GetTemplateByName(s.Template.Name, ctx.Get(r, "user_id").(int64)) if err == gorm.ErrRecordNotFound { - Logger.Printf("Error - Template %s does not exist", s.Template.Name) + log.WithFields(logrus.Fields{ + "template": s.Template.Name, + }).Error("Template does not exist") JSONResponse(w, models.Response{Success: false, Message: models.ErrTemplateNotFound.Error()}, http.StatusBadRequest) return } else if err != nil { - Logger.Println(err) + log.Error(err) JSONResponse(w, models.Response{Success: false, Message: err.Error()}, http.StatusBadRequest) return } @@ -705,7 +709,7 @@ func API_Send_Test_Email(w http.ResponseWriter, r *http.Request) { // If the Sending Profile doesn't exist, let's err on the side // of caution and assume that the validation failure was more important. if lookupErr != nil { - Logger.Println(err) + log.Error(err) JSONResponse(w, models.Response{Success: false, Message: err.Error()}, http.StatusBadRequest) return } @@ -728,7 +732,7 @@ func JSONResponse(w http.ResponseWriter, d interface{}, c int) { dj, err := json.MarshalIndent(d, "", " ") if err != nil { http.Error(w, "Error creating JSON response", http.StatusInternalServerError) - Logger.Println(err) + log.Error(err) } w.Header().Set("Content-Type", "application/json") w.WriteHeader(c) diff --git a/controllers/phish.go b/controllers/phish.go index 4e8eed4f..57677c6b 100644 --- a/controllers/phish.go +++ b/controllers/phish.go @@ -13,6 +13,7 @@ import ( "strings" ctx "github.com/gophish/gophish/context" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/models" "github.com/gorilla/mux" ) @@ -51,7 +52,7 @@ func PhishTracker(w http.ResponseWriter, r *http.Request) { if err != nil { // Log the error if it wasn't something we can safely ignore if err != ErrInvalidRequest && err != ErrCampaignComplete { - Logger.Println(err) + log.Error(err) } http.NotFound(w, r) return @@ -68,7 +69,7 @@ func PhishTracker(w http.ResponseWriter, r *http.Request) { } err = rs.UpdateStatus(models.EVENT_OPENED) if err != nil { - Logger.Println(err) + log.Error(err) } http.ServeFile(w, r, "static/images/pixel.png") } @@ -79,7 +80,7 @@ func PhishReporter(w http.ResponseWriter, r *http.Request) { if err != nil { // Log the error if it wasn't something we can safely ignore if err != ErrInvalidRequest && err != ErrCampaignComplete { - Logger.Println(err) + log.Error(err) } http.NotFound(w, r) return @@ -91,7 +92,7 @@ func PhishReporter(w http.ResponseWriter, r *http.Request) { err = rs.UpdateReported(true) if err != nil { - Logger.Println(err) + log.Error(err) } w.WriteHeader(http.StatusNoContent) } @@ -103,7 +104,7 @@ func PhishHandler(w http.ResponseWriter, r *http.Request) { if err != nil { // Log the error if it wasn't something we can safely ignore if err != ErrInvalidRequest && err != ErrCampaignComplete { - Logger.Println(err) + log.Error(err) } http.NotFound(w, r) return @@ -113,7 +114,7 @@ func PhishHandler(w http.ResponseWriter, r *http.Request) { rj := ctx.Get(r, "details").([]byte) p, err := models.GetPage(c.PageId, c.UserId) if err != nil { - Logger.Println(err) + log.Error(err) http.NotFound(w, r) return } @@ -124,7 +125,7 @@ func PhishHandler(w http.ResponseWriter, r *http.Request) { } err = c.AddEvent(models.Event{Email: rs.Email, Message: models.EVENT_CLICKED, Details: string(rj)}) if err != nil { - Logger.Println(err) + log.Error(err) } case r.Method == "POST": // If data was POST'ed, let's record it @@ -132,7 +133,7 @@ func PhishHandler(w http.ResponseWriter, r *http.Request) { // Store the data in an event c.AddEvent(models.Event{Email: rs.Email, Message: models.EVENT_DATA_SUBMIT, Details: string(rj)}) if err != nil { - Logger.Println(err) + log.Error(err) } // Redirect to the desired page if p.RedirectURL != "" { @@ -143,13 +144,13 @@ func PhishHandler(w http.ResponseWriter, r *http.Request) { var htmlBuff bytes.Buffer tmpl, err := template.New("html_template").Parse(p.HTML) if err != nil { - Logger.Println(err) + log.Error(err) http.NotFound(w, r) return } f, err := mail.ParseAddress(c.SMTP.FromAddress) if err != nil { - Logger.Println(err) + log.Error(err) } fn := f.Name if fn == "" { @@ -172,7 +173,7 @@ func PhishHandler(w http.ResponseWriter, r *http.Request) { } err = tmpl.Execute(&htmlBuff, rsf) if err != nil { - Logger.Println(err) + log.Error(err) http.NotFound(w, r) return } @@ -188,7 +189,7 @@ func RobotsHandler(w http.ResponseWriter, r *http.Request) { func setupContext(r *http.Request) (error, *http.Request) { err := r.ParseForm() if err != nil { - Logger.Println(err) + log.Error(err) return err, r } id := r.Form.Get(models.RecipientParameter) @@ -201,7 +202,7 @@ func setupContext(r *http.Request) (error, *http.Request) { } c, err := models.GetCampaign(rs.CampaignId, rs.UserId) if err != nil { - Logger.Println(err) + log.Error(err) return err, r } // Don't process events for completed campaigns @@ -210,7 +211,7 @@ func setupContext(r *http.Request) (error, *http.Request) { } ip, _, err := net.SplitHostPort(r.RemoteAddr) if err != nil { - Logger.Println(err) + log.Error(err) return err, r } // Respect X-Forwarded headers @@ -220,7 +221,7 @@ func setupContext(r *http.Request) (error, *http.Request) { // Handle post processing such as GeoIP err = rs.UpdateGeo(ip) if err != nil { - Logger.Println(err) + log.Error(err) } d := eventDetails{ Payload: r.Form, diff --git a/controllers/route.go b/controllers/route.go index 3fdca4f4..94bb734c 100644 --- a/controllers/route.go +++ b/controllers/route.go @@ -3,14 +3,13 @@ package controllers import ( "fmt" "html/template" - "log" "net/http" "net/url" - "os" "github.com/gophish/gophish/auth" "github.com/gophish/gophish/config" ctx "github.com/gophish/gophish/context" + log "github.com/gophish/gophish/logger" mid "github.com/gophish/gophish/middleware" "github.com/gophish/gophish/models" "github.com/gorilla/csrf" @@ -18,9 +17,6 @@ import ( "github.com/gorilla/sessions" ) -// Logger is used to send logging messages to stdout. -var Logger = log.New(os.Stdout, " ", log.Ldate|log.Ltime|log.Lshortfile) - // CreateAdminRouter creates the routes for handling requests to the web interface. // This function returns an http.Handler to be used in http.ListenAndServe(). func CreateAdminRouter() http.Handler { @@ -101,7 +97,7 @@ func Register(w http.ResponseWriter, r *http.Request) { templates := template.New("template") _, err := templates.ParseFiles("templates/register.html", "templates/flashes.html") if err != nil { - Logger.Println(err) + log.Error(err) } template.Must(templates, err).ExecuteTemplate(w, "base", params) case r.Method == "POST": @@ -116,7 +112,7 @@ func Register(w http.ResponseWriter, r *http.Request) { } // Check the error m := err.Error() - Logger.Println(err) + log.Error(err) Flash(w, r, "danger", m) session.Save(r, w) http.Redirect(w, r, "/register", 302) @@ -255,14 +251,14 @@ func Login(w http.ResponseWriter, r *http.Request) { templates := template.New("template") _, err := templates.ParseFiles("templates/login.html", "templates/flashes.html") if err != nil { - Logger.Println(err) + log.Error(err) } template.Must(templates, err).ExecuteTemplate(w, "base", params) case r.Method == "POST": //Attempt to login succ, u, err := auth.Login(r) if err != nil { - Logger.Println(err) + log.Error(err) } //If we've logged in, save the session and redirect to the dashboard if succ { @@ -284,7 +280,7 @@ func Login(w http.ResponseWriter, r *http.Request) { templates := template.New("template") _, err := templates.ParseFiles("templates/login.html", "templates/flashes.html") if err != nil { - Logger.Println(err) + log.Error(err) } w.Header().Set("Content-Type", "text/html; charset=utf-8") w.WriteHeader(http.StatusUnauthorized) @@ -319,7 +315,7 @@ func Clone(w http.ResponseWriter, r *http.Request) { return } if url, ok := vars["url"]; ok { - Logger.Println(url) + log.Error(url) } http.Error(w, "No URL given.", http.StatusBadRequest) } @@ -328,7 +324,7 @@ func getTemplate(w http.ResponseWriter, tmpl string) *template.Template { templates := template.New("template") _, err := templates.ParseFiles("templates/base.html", "templates/"+tmpl+".html", "templates/flashes.html") if err != nil { - Logger.Println(err) + log.Error(err) } return template.Must(templates, err) } diff --git a/gophish.go b/gophish.go index a4cd7c06..d0aee6d9 100644 --- a/gophish.go +++ b/gophish.go @@ -29,7 +29,6 @@ import ( "compress/gzip" "context" "io/ioutil" - "log" "net/http" "os" "sync" @@ -40,6 +39,7 @@ import ( "github.com/gophish/gophish/auth" "github.com/gophish/gophish/config" "github.com/gophish/gophish/controllers" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/mailer" "github.com/gophish/gophish/models" "github.com/gophish/gophish/util" @@ -47,17 +47,16 @@ import ( ) var ( - Logger = log.New(os.Stdout, " ", log.Ldate|log.Ltime|log.Lshortfile) - configPath = kingpin.Flag("config", "Location of config.json.").Default("./config.json").String() disableMailer = kingpin.Flag("disable-mailer", "Disable the mailer (for use with multi-system deployments)").Bool() ) func main() { // Load the version + version, err := ioutil.ReadFile("./VERSION") if err != nil { - Logger.Fatalln(err) + log.Fatal(err) } kingpin.Version(string(version)) @@ -79,13 +78,13 @@ func main() { // Setup the global variables and settings err = models.Setup() if err != nil { - Logger.Fatalln(err) + log.Fatal(err) } // Unlock any maillogs that may have been locked for processing // when Gophish was last shutdown. err = models.UnlockAllMailLogs() if err != nil { - Logger.Fatalln(err) + log.Fatal(err) } wg := &sync.WaitGroup{} wg.Add(1) @@ -98,14 +97,14 @@ func main() { if config.Conf.AdminConf.UseTLS { // use TLS for Admin web server if available err := util.CheckAndCreateSSL(config.Conf.AdminConf.CertPath, config.Conf.AdminConf.KeyPath) if err != nil { - Logger.Fatal(err) + log.Fatal(err) } - Logger.Printf("Starting admin server at https://%s\n", config.Conf.AdminConf.ListenURL) - Logger.Fatal(http.ListenAndServeTLS(config.Conf.AdminConf.ListenURL, config.Conf.AdminConf.CertPath, config.Conf.AdminConf.KeyPath, - handlers.CombinedLoggingHandler(os.Stdout, adminHandler))) + log.Infof("Starting admin server at https://%s\n", config.Conf.AdminConf.ListenURL) + log.Info(http.ListenAndServeTLS(config.Conf.AdminConf.ListenURL, config.Conf.AdminConf.CertPath, config.Conf.AdminConf.KeyPath, + handlers.CombinedLoggingHandler(log.Writer(), adminHandler))) } else { - Logger.Printf("Starting admin server at http://%s\n", config.Conf.AdminConf.ListenURL) - Logger.Fatal(http.ListenAndServe(config.Conf.AdminConf.ListenURL, handlers.CombinedLoggingHandler(os.Stdout, adminHandler))) + log.Infof("Starting admin server at http://%s\n", config.Conf.AdminConf.ListenURL) + log.Info(http.ListenAndServe(config.Conf.AdminConf.ListenURL, handlers.CombinedLoggingHandler(os.Stdout, adminHandler))) } }() wg.Add(1) @@ -113,12 +112,12 @@ func main() { defer wg.Done() phishHandler := gziphandler.GzipHandler(controllers.CreatePhishingRouter()) if config.Conf.PhishConf.UseTLS { // use TLS for Phish web server if available - Logger.Printf("Starting phishing server at https://%s\n", config.Conf.PhishConf.ListenURL) - Logger.Fatal(http.ListenAndServeTLS(config.Conf.PhishConf.ListenURL, config.Conf.PhishConf.CertPath, config.Conf.PhishConf.KeyPath, - handlers.CombinedLoggingHandler(os.Stdout, phishHandler))) + log.Infof("Starting phishing server at https://%s\n", config.Conf.PhishConf.ListenURL) + log.Info(http.ListenAndServeTLS(config.Conf.PhishConf.ListenURL, config.Conf.PhishConf.CertPath, config.Conf.PhishConf.KeyPath, + handlers.CombinedLoggingHandler(log.Writer(), phishHandler))) } else { - Logger.Printf("Starting phishing server at http://%s\n", config.Conf.PhishConf.ListenURL) - Logger.Fatal(http.ListenAndServe(config.Conf.PhishConf.ListenURL, handlers.CombinedLoggingHandler(os.Stdout, phishHandler))) + log.Infof("Starting phishing server at http://%s\n", config.Conf.PhishConf.ListenURL) + log.Fatal(http.ListenAndServe(config.Conf.PhishConf.ListenURL, handlers.CombinedLoggingHandler(os.Stdout, phishHandler))) } }() wg.Wait() diff --git a/logger/doc.go b/logger/doc.go new file mode 100644 index 00000000..d99875a3 --- /dev/null +++ b/logger/doc.go @@ -0,0 +1,29 @@ +/* +gophish - Open-Source Phishing Framework + +The MIT License (MIT) + +Copyright (c) 2013 Jordan Wright + +Permission is hereby granted, free of charge, to any person obtaining a copy +of this software and associated documentation files (the "Software"), to deal +in the Software without restriction, including without limitation the rights +to use, copy, modify, merge, publish, distribute, sublicense, and/or sell +copies of the Software, and to permit persons to whom the Software is +furnished to do so, subject to the following conditions: + +The above copyright notice and this permission notice shall be included in +all copies or substantial portions of the Software. + +THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR +IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, +FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE +AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER +LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, +OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN +THE SOFTWARE. +*/ + +// Package logger contains a wrapper around logrus to support a centralized +// logging config. +package logger diff --git a/logger/logger.go b/logger/logger.go new file mode 100644 index 00000000..ba8372da --- /dev/null +++ b/logger/logger.go @@ -0,0 +1,65 @@ +package logger + +import ( + "io" + + "github.com/sirupsen/logrus" +) + +// Logger is the main logger that is abstracted in this package. +// It is exported here for use with gorm. +var Logger *logrus.Logger + +func init() { + Logger = logrus.New() + Logger.SetLevel(logrus.InfoLevel) + Logger.Formatter = &logrus.TextFormatter{DisableColors: true} +} + +func Debug(args ...interface{}) { + Logger.Debug(args...) +} + +func Debugf(format string, args ...interface{}) { + Logger.Debugf(format, args...) +} + +func Info(args ...interface{}) { + Logger.Info(args...) +} + +func Infof(format string, args ...interface{}) { + Logger.Infof(format, args...) +} + +func Error(args ...interface{}) { + Logger.Error(args...) +} + +func Errorf(format string, args ...interface{}) { + Logger.Errorf(format, args...) +} + +func Warn(args ...interface{}) { + Logger.Warn(args...) +} + +func Warnf(format string, args ...interface{}) { + Logger.Warnf(format, args...) +} + +func Fatal(args ...interface{}) { + Logger.Fatal(args...) +} + +func Fatalf(format string, args ...interface{}) { + Logger.Fatalf(format, args...) +} + +func WithFields(fields logrus.Fields) *logrus.Entry { + return Logger.WithFields(fields) +} + +func Writer() *io.PipeWriter { + return Logger.Writer() +} diff --git a/mailer/mailer.go b/mailer/mailer.go index 771a8f1c..22db4a6f 100644 --- a/mailer/mailer.go +++ b/mailer/mailer.go @@ -4,11 +4,11 @@ import ( "context" "fmt" "io" - "log" "net/textproto" - "os" "github.com/gophish/gomail" + log "github.com/gophish/gophish/logger" + "github.com/sirupsen/logrus" ) // MaxReconnectAttempts is the maximum number of times we should reconnect to a server @@ -29,9 +29,6 @@ func (e *ErrMaxConnectAttempts) Error() string { return errString } -// Logger is the logger for the worker -var Logger = log.New(os.Stdout, " ", log.Ldate|log.Ltime|log.Lshortfile) - // Sender exposes the common operations required for sending email. type Sender interface { Send(from string, to []string, msg io.WriterTo) error @@ -86,7 +83,7 @@ func (mw *MailWorker) Start(ctx context.Context) { return case ms := <-mw.Queue: go func(ctx context.Context, ms []Mail) { - Logger.Printf("Mailer got %d mail to send", len(ms)) + log.Infof("Mailer got %d mail to send", len(ms)) dialer, err := ms[0].GetDialer() if err != nil { errorMail(err, ms) @@ -141,6 +138,7 @@ func dialHost(ctx context.Context, dialer Dialer) (Sender, error) { func sendMail(ctx context.Context, dialer Dialer, ms []Mail) { sender, err := dialHost(ctx, dialer) if err != nil { + log.Warn(err) errorMail(err, ms) return } @@ -157,6 +155,7 @@ func sendMail(ctx context.Context, dialer Dialer, ms []Mail) { err = m.Generate(message) if err != nil { + log.Warn(err) m.Error(err) continue } @@ -169,6 +168,10 @@ func sendMail(ctx context.Context, dialer Dialer, ms []Mail) { // We'll reset the connection so future messages don't incur a // different error (see https://github.com/gophish/gophish/issues/787). case te.Code >= 400 && te.Code <= 499: + log.WithFields(logrus.Fields{ + "code": te.Code, + "email": message.GetHeader("To")[0], + }).Warn(err) m.Backoff(err) sender.Reset() continue @@ -176,12 +179,20 @@ func sendMail(ctx context.Context, dialer Dialer, ms []Mail) { // since the RFC specifies that running the same commands won't work next time. // We should reset our sender and error this message out. case te.Code >= 500 && te.Code <= 599: + log.WithFields(logrus.Fields{ + "code": te.Code, + "email": message.GetHeader("To")[0], + }).Warn(err) m.Error(err) sender.Reset() continue // If something else happened, let's just error out and reset the // sender default: + log.WithFields(logrus.Fields{ + "code": "unknown", + "email": message.GetHeader("To")[0], + }).Warn(err) m.Error(err) sender.Reset() continue @@ -190,6 +201,9 @@ func sendMail(ctx context.Context, dialer Dialer, ms []Mail) { // This likely indicates that something happened to the underlying // connection. We'll try to reconnect and, if that fails, we'll // error out the remaining emails. + log.WithFields(logrus.Fields{ + "email": message.GetHeader("To")[0], + }).Warn(err) origErr := err sender, err = dialHost(ctx, dialer) if err != nil { @@ -200,6 +214,9 @@ func sendMail(ctx context.Context, dialer Dialer, ms []Mail) { continue } } + log.WithFields(logrus.Fields{ + "email": message.GetHeader("To")[0], + }).Info("Email sent") m.Success() } } diff --git a/models/campaign.go b/models/campaign.go index 4760a866..7cc15ca4 100644 --- a/models/campaign.go +++ b/models/campaign.go @@ -4,7 +4,9 @@ import ( "errors" "time" + log "github.com/gophish/gophish/logger" "github.com/jinzhu/gorm" + "github.com/sirupsen/logrus" ) // Campaign is a struct representing a created campaign @@ -30,15 +32,15 @@ type Campaign struct { // CampaignResults is a struct representing the results from a campaign type CampaignResults struct { - Id int64 `json:"id"` - Name string `json:"name"` - Status string `json:"status"` - Reported string `json:"reported"` - Results []Result `json:"results, omitempty"` - Events []Event `json:"timeline,omitempty"` + Id int64 `json:"id"` + Name string `json:"name"` + Status string `json:"status"` + Reported string `json:"reported"` + Results []Result `json:"results, omitempty"` + Events []Event `json:"timeline,omitempty"` } -// CampaignsSummary is a struct representing the overview of campaigns +// CampaignSummaries is a struct representing the overview of campaigns type CampaignSummaries struct { Total int64 `json:"total"` Campaigns []CampaignSummary `json:"campaigns"` @@ -84,7 +86,7 @@ var ErrSMTPNotSpecified = errors.New("No sending profile specified") // ErrTemplateNotFound indicates the template specified does not exist in the database var ErrTemplateNotFound = errors.New("Template not found") -// ErrGroupnNotFound indicates a group specified by the user does not exist in the database +// ErrGroupNotFound indicates a group specified by the user does not exist in the database var ErrGroupNotFound = errors.New("Group not found") // ErrPageNotFound indicates a page specified by the user does not exist in the database @@ -133,12 +135,12 @@ func (c *Campaign) AddEvent(e Event) error { func (c *Campaign) getDetails() error { err = db.Model(c).Related(&c.Results).Error if err != nil { - Logger.Printf("%s: results not found for campaign\n", err) + log.Warnf("%s: results not found for campaign", err) return err } err = db.Model(c).Related(&c.Events).Error if err != nil { - Logger.Printf("%s: events not found for campaign\n", err) + log.Warnf("%s: events not found for campaign", err) return err } err = db.Table("templates").Where("id=?", c.TemplateId).Find(&c.Template).Error @@ -147,11 +149,11 @@ func (c *Campaign) getDetails() error { return err } c.Template = Template{Name: "[Deleted]"} - Logger.Printf("%s: template not found for campaign\n", err) + log.Warnf("%s: template not found for campaign", err) } err = db.Where("template_id=?", c.Template.Id).Find(&c.Template.Attachments).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Warn(err) return err } err = db.Table("pages").Where("id=?", c.PageId).Find(&c.Page).Error @@ -160,7 +162,7 @@ func (c *Campaign) getDetails() error { return err } c.Page = Page{Name: "[Deleted]"} - Logger.Printf("%s: page not found for campaign\n", err) + log.Warnf("%s: page not found for campaign", err) } err = db.Table("smtp").Where("id=?", c.SMTPId).Find(&c.SMTP).Error if err != nil { @@ -169,11 +171,11 @@ func (c *Campaign) getDetails() error { return err } c.SMTP = SMTP{Name: "[Deleted]"} - Logger.Printf("%s: sending profile not found for campaign\n", err) + log.Warnf("%s: sending profile not found for campaign", err) } err = db.Where("smtp_id=?", c.SMTP.Id).Find(&c.SMTP.Headers).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Warn(err) return err } return nil @@ -234,12 +236,12 @@ func GetCampaigns(uid int64) ([]Campaign, error) { cs := []Campaign{} err := db.Model(&User{Id: uid}).Related(&cs).Error if err != nil { - Logger.Println(err) + log.Error(err) } - for i, _ := range cs { + for i := range cs { err = cs[i].getDetails() if err != nil { - Logger.Println(err) + log.Error(err) } } return cs, err @@ -255,13 +257,13 @@ func GetCampaignSummaries(uid int64) (CampaignSummaries, error) { query = query.Select("id, name, created_date, launch_date, completed_date, status") err := query.Scan(&cs).Error if err != nil { - Logger.Println(err) + log.Error(err) return overview, err } for i := range cs { s, err := getCampaignStats(cs[i].Id) if err != nil { - Logger.Println(err) + log.Error(err) return overview, err } cs[i].Stats = s @@ -278,12 +280,12 @@ func GetCampaignSummary(id int64, uid int64) (CampaignSummary, error) { query = query.Select("id, name, created_date, launch_date, completed_date, status") err := query.Scan(&cs).Error if err != nil { - Logger.Println(err) + log.Error(err) return cs, err } s, err := getCampaignStats(cs.Id) if err != nil { - Logger.Println(err) + log.Error(err) return cs, err } cs.Stats = s @@ -295,28 +297,32 @@ func GetCampaign(id int64, uid int64) (Campaign, error) { c := Campaign{} err := db.Where("id = ?", id).Where("user_id = ?", uid).Find(&c).Error if err != nil { - Logger.Printf("%s: campaign not found\n", err) + log.Errorf("%s: campaign not found", err) return c, err } err = c.getDetails() return c, err } +// GetCampaignResults returns just the campaign results for the given campaign func GetCampaignResults(id int64, uid int64) (CampaignResults, error) { cr := CampaignResults{} err := db.Table("campaigns").Where("id=? and user_id=?", id, uid).Find(&cr).Error if err != nil { - Logger.Printf("%s: campaign not found\n", err) + log.WithFields(logrus.Fields{ + "campaign_id": id, + "error": err, + }).Error(err) return cr, err } err = db.Table("results").Where("campaign_id=? and user_id=?", cr.Id, uid).Find(&cr.Results).Error if err != nil { - Logger.Printf("%s: results not found for campaign\n", err) + log.Errorf("%s: results not found for campaign", err) return cr, err } err = db.Table("events").Where("campaign_id=?", cr.Id).Find(&cr.Events).Error if err != nil { - Logger.Printf("%s: events not found for campaign\n", err) + log.Errorf("%s: events not found for campaign", err) return cr, err } return cr, err @@ -328,13 +334,13 @@ func GetQueuedCampaigns(t time.Time) ([]Campaign, error) { err := db.Where("launch_date <= ?", t). Where("status = ?", CAMPAIGN_QUEUED).Find(&cs).Error if err != nil { - Logger.Println(err) + log.Error(err) } - Logger.Printf("Found %d Campaigns to run\n", len(cs)) - for i, _ := range cs { + log.Infof("Found %d Campaigns to run\n", len(cs)) + for i := range cs { err = cs[i].getDetails() if err != nil { - Logger.Println(err) + log.Error(err) } } return cs, err @@ -362,20 +368,24 @@ func PostCampaign(c *Campaign, uid int64) error { for i, g := range c.Groups { c.Groups[i], err = GetGroupByName(g.Name, uid) if err == gorm.ErrRecordNotFound { - Logger.Printf("Error - Group %s does not exist", g.Name) + log.WithFields(logrus.Fields{ + "group": g.Name, + }).Error("Group does not exist") return ErrGroupNotFound } else if err != nil { - Logger.Println(err) + log.Error(err) return err } } // Check to make sure the template exists t, err := GetTemplateByName(c.Template.Name, uid) if err == gorm.ErrRecordNotFound { - Logger.Printf("Error - Template %s does not exist", t.Name) + log.WithFields(logrus.Fields{ + "template": t.Name, + }).Error("Template does not exist") return ErrTemplateNotFound } else if err != nil { - Logger.Println(err) + log.Error(err) return err } c.Template = t @@ -383,10 +393,12 @@ func PostCampaign(c *Campaign, uid int64) error { // Check to make sure the page exists p, err := GetPageByName(c.Page.Name, uid) if err == gorm.ErrRecordNotFound { - Logger.Printf("Error - Page %s does not exist", p.Name) + log.WithFields(logrus.Fields{ + "page": p.Name, + }).Error("Page does not exist") return ErrPageNotFound } else if err != nil { - Logger.Println(err) + log.Error(err) return err } c.Page = p @@ -394,10 +406,12 @@ func PostCampaign(c *Campaign, uid int64) error { // Check to make sure the sending profile exists s, err := GetSMTPByName(c.SMTP.Name, uid) if err == gorm.ErrRecordNotFound { - Logger.Printf("Error - Sending profile %s does not exist", s.Name) - return ErrPageNotFound + log.WithFields(logrus.Fields{ + "smtp": s.Name, + }).Error("Sending profile does not exist") + return ErrSMTPNotFound } else if err != nil { - Logger.Println(err) + log.Error(err) return err } c.SMTP = s @@ -405,12 +419,12 @@ func PostCampaign(c *Campaign, uid int64) error { // Insert into the DB err = db.Save(c).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } err = c.AddEvent(Event{Message: "Campaign Created"}) if err != nil { - Logger.Println(err) + log.Error(err) } // Insert all the results resultMap := make(map[string]bool) @@ -439,18 +453,19 @@ func PostCampaign(c *Campaign, uid int64) error { } err = r.GenerateId() if err != nil { - Logger.Println(err) + log.Error(err) continue } err = db.Save(r).Error if err != nil { - Logger.Printf("Error adding result record for target %s\n", t.Email) - Logger.Println(err) + log.WithFields(logrus.Fields{ + "email": t.Email, + }).Error(err) } c.Results = append(c.Results, *r) err = GenerateMailLog(c, r) if err != nil { - Logger.Println(err) + log.Error(err) continue } } @@ -461,22 +476,24 @@ func PostCampaign(c *Campaign, uid int64) error { //DeleteCampaign deletes the specified campaign func DeleteCampaign(id int64) error { - Logger.Printf("Deleting campaign %d\n", id) + log.WithFields(logrus.Fields{ + "campaign_id": id, + }).Info("Deleting campaign") // Delete all the campaign results err := db.Where("campaign_id=?", id).Delete(&Result{}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } err = db.Where("campaign_id=?", id).Delete(&Event{}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } // Delete the campaign err = db.Delete(&Campaign{Id: id}).Error if err != nil { - Logger.Println(err) + log.Error(err) } return err } @@ -484,7 +501,9 @@ func DeleteCampaign(id int64) error { // CompleteCampaign effectively "ends" a campaign. // Any future emails clicked will return a simple "404" page. func CompleteCampaign(id int64, uid int64) error { - Logger.Printf("Marking campaign %d as complete\n", id) + log.WithFields(logrus.Fields{ + "campaign_id": id, + }).Info("Marking campaign as complete") c, err := GetCampaign(id, uid) if err != nil { return err @@ -498,7 +517,7 @@ func CompleteCampaign(id int64, uid int64) error { c.Status = CAMPAIGN_COMPLETE err = db.Where("id=? and user_id=?", id, uid).Save(&c).Error if err != nil { - Logger.Println(err) + log.Error(err) } return err } diff --git a/models/email_request.go b/models/email_request.go index 8ddb10e2..c255b007 100644 --- a/models/email_request.go +++ b/models/email_request.go @@ -8,6 +8,7 @@ import ( "strings" "github.com/gophish/gomail" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/mailer" ) @@ -79,12 +80,12 @@ func (s *SendTestEmailRequest) Generate(msg *gomail.Message) error { for _, header := range s.SMTP.Headers { key, err := buildTemplate(header.Key, s) if err != nil { - Logger.Println(err) + log.Error(err) } value, err := buildTemplate(header.Value, s) if err != nil { - Logger.Println(err) + log.Error(err) } // Add our header immediately @@ -94,7 +95,7 @@ func (s *SendTestEmailRequest) Generate(msg *gomail.Message) error { // Parse remaining templates subject, err := buildTemplate(s.Template.Subject, s) if err != nil { - Logger.Println(err) + log.Error(err) } // don't set the Subject header if it is blank if len(subject) != 0 { @@ -105,14 +106,14 @@ func (s *SendTestEmailRequest) Generate(msg *gomail.Message) error { if s.Template.Text != "" { text, err := buildTemplate(s.Template.Text, s) if err != nil { - Logger.Println(err) + log.Error(err) } msg.SetBody("text/plain", text) } if s.Template.HTML != "" { html, err := buildTemplate(s.Template.HTML, s) if err != nil { - Logger.Println(err) + log.Error(err) } if s.Template.Text == "" { msg.SetBody("text/html", html) diff --git a/models/group.go b/models/group.go index b1b1c8fc..2415d159 100644 --- a/models/group.go +++ b/models/group.go @@ -6,7 +6,9 @@ import ( "net/mail" "time" + log "github.com/gophish/gophish/logger" "github.com/jinzhu/gorm" + "github.com/sirupsen/logrus" ) // Group contains the fields needed for a user -> group mapping @@ -89,13 +91,13 @@ func GetGroups(uid int64) ([]Group, error) { gs := []Group{} err := db.Where("user_id=?", uid).Find(&gs).Error if err != nil { - Logger.Println(err) + log.Error(err) return gs, err } - for i, _ := range gs { + for i := range gs { gs[i].Targets, err = GetTargets(gs[i].Id) if err != nil { - Logger.Println(err) + log.Error(err) } } return gs, nil @@ -108,7 +110,7 @@ func GetGroupSummaries(uid int64) (GroupSummaries, error) { query := db.Table("groups").Where("user_id=?", uid) err := query.Select("id, name, modified_date").Scan(&gs.Groups).Error if err != nil { - Logger.Println(err) + log.Error(err) return gs, err } for i := range gs.Groups { @@ -127,12 +129,12 @@ func GetGroup(id int64, uid int64) (Group, error) { g := Group{} err := db.Where("user_id=? and id=?", uid, id).Find(&g).Error if err != nil { - Logger.Println(err) + log.Error(err) return g, err } g.Targets, err = GetTargets(g.Id) if err != nil { - Logger.Println(err) + log.Error(err) } return g, nil } @@ -143,7 +145,7 @@ func GetGroupSummary(id int64, uid int64) (GroupSummary, error) { query := db.Table("groups").Where("user_id=? and id=?", uid, id) err := query.Select("id, name, modified_date").Scan(&g).Error if err != nil { - Logger.Println(err) + log.Error(err) return g, err } query = db.Table("group_targets").Where("group_id=?", id) @@ -159,12 +161,12 @@ func GetGroupByName(n string, uid int64) (Group, error) { g := Group{} err := db.Where("user_id=? and name=?", uid, n).Find(&g).Error if err != nil { - Logger.Println(err) + log.Error(err) return g, err } g.Targets, err = GetTargets(g.Id) if err != nil { - Logger.Println(err) + log.Error(err) } return g, err } @@ -177,7 +179,7 @@ func PostGroup(g *Group) error { // Insert the group into the DB err = db.Save(g).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } for _, t := range g.Targets { @@ -195,7 +197,9 @@ func PutGroup(g *Group) error { ts := []Target{} ts, err = GetTargets(g.Id) if err != nil { - Logger.Printf("Error getting targets from group ID: %d", g.Id) + log.WithFields(logrus.Fields{ + "group_id": g.Id, + }).Error("Error getting targets from group") return err } // Check existing targets, removing any that are no longer in the group. @@ -213,7 +217,9 @@ func PutGroup(g *Group) error { if !tExists { err = db.Where("group_id=? and target_id=?", g.Id, t.Id).Delete(&GroupTarget{}).Error if err != nil { - Logger.Printf("Error deleting email %s\n", t.Email) + log.WithFields(logrus.Fields{ + "email": t.Email, + }).Error("Error deleting email") } } } @@ -237,7 +243,7 @@ func PutGroup(g *Group) error { } err = db.Save(g).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } return nil @@ -248,13 +254,13 @@ func DeleteGroup(g *Group) error { // Delete all the group_targets entries for this group err := db.Where("group_id=?", g.Id).Delete(&GroupTarget{}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } // Delete the group itself err = db.Delete(g).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } return err @@ -262,30 +268,36 @@ func DeleteGroup(g *Group) error { func insertTargetIntoGroup(t Target, gid int64) error { if _, err = mail.ParseAddress(t.Email); err != nil { - Logger.Printf("Invalid email %s\n", t.Email) + log.WithFields(logrus.Fields{ + "email": t.Email, + }).Error("Invalid email") return err } trans := db.Begin() trans.Where(t).FirstOrCreate(&t) if err != nil { - Logger.Printf("Error adding target: %s\n", t.Email) + log.WithFields(logrus.Fields{ + "email": t.Email, + }).Error("Error adding target") return err } err = trans.Where("group_id=? and target_id=?", gid, t.Id).Find(&GroupTarget{}).Error if err == gorm.ErrRecordNotFound { err = trans.Save(&GroupTarget{GroupId: gid, TargetId: t.Id}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } } if err != nil { - Logger.Printf("Error adding many-many mapping for %s\n", t.Email) + log.WithFields(logrus.Fields{ + "email": t.Email, + }).Error("Error adding many-many mapping") return err } err = trans.Commit().Error if err != nil { - Logger.Printf("Error committing db changes\n") + log.Error("Error committing db changes") return err } return nil @@ -300,7 +312,9 @@ func UpdateTarget(target Target) error { } err := db.Model(&target).Where("id = ?", target.Id).Updates(targetInfo).Error if err != nil { - Logger.Printf("Error updating target information for %s\n", target.Email) + log.WithFields(logrus.Fields{ + "email": target.Email, + }).Error("Error updating target information") } return err } diff --git a/models/maillog.go b/models/maillog.go index 8ed9741e..dffd6422 100644 --- a/models/maillog.go +++ b/models/maillog.go @@ -16,6 +16,7 @@ import ( "time" "github.com/gophish/gomail" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/mailer" ) @@ -120,7 +121,7 @@ func (m *MailLog) addError(e error) error { } ej, err := json.Marshal(es) if err != nil { - Logger.Println(err) + log.Warn(err) } err = c.AddEvent(Event{Email: r.Email, Message: EVENT_SENDING_ERROR, Details: string(ej)}) return err @@ -130,19 +131,21 @@ func (m *MailLog) addError(e error) error { // maillog refers to. Since MailLog errors are permanent, // this action also deletes the maillog. func (m *MailLog) Error(e error) error { - Logger.Printf("Erroring out result %s\n", m.RId) r, err := GetResult(m.RId) if err != nil { + log.Warn(err) return err } // Update the result err = r.UpdateStatus(ERROR) if err != nil { + log.Warn(err) return err } // Update the campaign events err = m.addError(e) if err != nil { + log.Warn(err) return err } err = db.Delete(m).Error @@ -247,12 +250,12 @@ func (m *MailLog) Generate(msg *gomail.Message) error { for _, header := range c.SMTP.Headers { key, err := buildTemplate(header.Key, td) if err != nil { - Logger.Println(err) + log.Warn(err) } value, err := buildTemplate(header.Value, td) if err != nil { - Logger.Println(err) + log.Warn(err) } // Add our header immediately @@ -262,7 +265,7 @@ func (m *MailLog) Generate(msg *gomail.Message) error { // Parse remaining templates subject, err := buildTemplate(c.Template.Subject, td) if err != nil { - Logger.Println(err) + log.Warn(err) } // don't set Subject header if the subject is empty if len(subject) != 0 { @@ -273,14 +276,14 @@ func (m *MailLog) Generate(msg *gomail.Message) error { if c.Template.Text != "" { text, err := buildTemplate(c.Template.Text, td) if err != nil { - Logger.Println(err) + log.Warn(err) } msg.SetBody("text/plain", text) } if c.Template.HTML != "" { html, err := buildTemplate(c.Template.HTML, td) if err != nil { - Logger.Println(err) + log.Warn(err) } if c.Template.Text == "" { msg.SetBody("text/html", html) @@ -309,7 +312,7 @@ func GetQueuedMailLogs(t time.Time) ([]*MailLog, error) { err := db.Where("send_date <= ? AND processing = ?", t, false). Find(&ms).Error if err != nil { - Logger.Println(err) + log.Warn(err) } return ms, err } diff --git a/models/models.go b/models/models.go index 8f3f60a7..eb7bfe2a 100644 --- a/models/models.go +++ b/models/models.go @@ -4,13 +4,12 @@ import ( "crypto/rand" "fmt" "io" - "log" - "os" "bitbucket.org/liamstask/goose/lib/goose" - _ "github.com/go-sql-driver/mysql" + _ "github.com/go-sql-driver/mysql" // Blank import needed to import mysql "github.com/gophish/gophish/config" + log "github.com/gophish/gophish/logger" "github.com/jinzhu/gorm" _ "github.com/mattn/go-sqlite3" // Blank import needed to import sqlite3 ) @@ -18,9 +17,6 @@ import ( var db *gorm.DB var err error -// Logger is a global logger used to show informational, warning, and error messages -var Logger = log.New(os.Stdout, " ", log.Ldate|log.Ltime|log.Lshortfile) - const ( CAMPAIGN_IN_PROGRESS string = "In progress" CAMPAIGN_QUEUED string = "Queued" @@ -92,22 +88,22 @@ func Setup() error { // Get the latest possible migration latest, err := goose.GetMostRecentDBVersion(migrateConf.MigrationsDir) if err != nil { - Logger.Println(err) + log.Error(err) return err } // Open our database connection db, err = gorm.Open(config.Conf.DBName, config.Conf.DBPath) db.LogMode(false) - db.SetLogger(Logger) + db.SetLogger(log.Logger) db.DB().SetMaxOpenConns(1) if err != nil { - Logger.Println(err) + log.Error(err) return err } // Migrate up to the latest version err = goose.RunMigrationsOnDb(migrateConf, migrateConf.MigrationsDir, latest, db.DB()) if err != nil { - Logger.Println(err) + log.Error(err) return err } // Create the admin user if it doesn't exist @@ -121,7 +117,7 @@ func Setup() error { initUser.ApiKey = generateSecureKey() err = db.Save(&initUser).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } } diff --git a/models/page.go b/models/page.go index 33277584..1a40abfb 100644 --- a/models/page.go +++ b/models/page.go @@ -6,6 +6,7 @@ import ( "time" "github.com/PuerkitoBio/goquery" + log "github.com/gophish/gophish/logger" ) // Page contains the fields used for a Page model @@ -77,7 +78,7 @@ func GetPages(uid int64) ([]Page, error) { ps := []Page{} err := db.Where("user_id=?", uid).Find(&ps).Error if err != nil { - Logger.Println(err) + log.Error(err) return ps, err } return ps, err @@ -88,7 +89,7 @@ func GetPage(id int64, uid int64) (Page, error) { p := Page{} err := db.Where("user_id=? and id=?", uid, id).Find(&p).Error if err != nil { - Logger.Println(err) + log.Error(err) } return p, err } @@ -98,7 +99,7 @@ func GetPageByName(n string, uid int64) (Page, error) { p := Page{} err := db.Where("user_id=? and name=?", uid, n).Find(&p).Error if err != nil { - Logger.Println(err) + log.Error(err) } return p, err } @@ -107,13 +108,13 @@ func GetPageByName(n string, uid int64) (Page, error) { func PostPage(p *Page) error { err := p.Validate() if err != nil { - Logger.Println(err) + log.Error(err) return err } // Insert into the DB err = db.Save(p).Error if err != nil { - Logger.Println(err) + log.Error(err) } return err } @@ -124,7 +125,7 @@ func PutPage(p *Page) error { err := p.Validate() err = db.Where("id=?", p.Id).Save(p).Error if err != nil { - Logger.Println(err) + log.Error(err) } return err } @@ -134,7 +135,7 @@ func PutPage(p *Page) error { func DeletePage(id int64, uid int64) error { err = db.Where("user_id=?", uid).Delete(Page{Id: id}).Error if err != nil { - Logger.Println(err) + log.Error(err) } return err } diff --git a/models/result.go b/models/result.go index 130a2614..b91f8795 100644 --- a/models/result.go +++ b/models/result.go @@ -3,12 +3,12 @@ package models import ( "crypto/rand" "fmt" - "log" "math/big" "net" "net/mail" "time" + log "github.com/gophish/gophish/logger" "github.com/jinzhu/gorm" "github.com/oschwald/maxminddb-golang" ) @@ -98,7 +98,7 @@ func (r *Result) GenerateId() error { return nil } -// Returns the email address to use in the "To" header of the email +// FormatAddress returns the email address to use in the "To" header of the email func (r *Result) FormatAddress() string { addr := r.Email if r.FirstName != "" && r.LastName != "" { diff --git a/models/smtp.go b/models/smtp.go index 2118485f..996aac70 100644 --- a/models/smtp.go +++ b/models/smtp.go @@ -10,6 +10,7 @@ import ( "time" "github.com/gophish/gomail" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/mailer" "github.com/jinzhu/gorm" ) @@ -104,7 +105,7 @@ func (s *SMTP) GetDialer() (mailer.Dialer, error) { // double check here. port, err := strconv.Atoi(hp[1]) if err != nil { - Logger.Println(err) + log.Error(err) return nil, err } d := gomail.NewDialer(hp[0], port, s.Username, s.Password) @@ -114,7 +115,7 @@ func (s *SMTP) GetDialer() (mailer.Dialer, error) { } hostname, err := os.Hostname() if err != nil { - Logger.Println(err) + log.Error(err) hostname = "localhost" } d.LocalName = hostname @@ -126,13 +127,13 @@ func GetSMTPs(uid int64) ([]SMTP, error) { ss := []SMTP{} err := db.Where("user_id=?", uid).Find(&ss).Error if err != nil { - Logger.Println(err) + log.Error(err) return ss, err } for i := range ss { err = db.Where("smtp_id=?", ss[i].Id).Find(&ss[i].Headers).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return ss, err } } @@ -144,11 +145,11 @@ func GetSMTP(id int64, uid int64) (SMTP, error) { s := SMTP{} err := db.Where("user_id=? and id=?", uid, id).Find(&s).Error if err != nil { - Logger.Println(err) + log.Error(err) } err = db.Where("smtp_id=?", s.Id).Find(&s.Headers).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return s, err } return s, err @@ -159,12 +160,12 @@ func GetSMTPByName(n string, uid int64) (SMTP, error) { s := SMTP{} err := db.Where("user_id=? and name=?", uid, n).Find(&s).Error if err != nil { - Logger.Println(err) + log.Error(err) return s, err } err = db.Where("smtp_id=?", s.Id).Find(&s.Headers).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) } return s, err } @@ -173,20 +174,20 @@ func GetSMTPByName(n string, uid int64) (SMTP, error) { func PostSMTP(s *SMTP) error { err := s.Validate() if err != nil { - Logger.Println(err) + log.Error(err) return err } // Insert into the DB err = db.Save(s).Error if err != nil { - Logger.Println(err) + log.Error(err) } // Save custom headers for i := range s.Headers { s.Headers[i].SMTPId = s.Id err := db.Save(&s.Headers[i]).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } } @@ -198,24 +199,24 @@ func PostSMTP(s *SMTP) error { func PutSMTP(s *SMTP) error { err := s.Validate() if err != nil { - Logger.Println(err) + log.Error(err) return err } err = db.Where("id=?", s.Id).Save(s).Error if err != nil { - Logger.Println(err) + log.Error(err) } // Delete all custom headers, and replace with new ones err = db.Where("smtp_id=?", s.Id).Delete(&Header{}).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return err } for i := range s.Headers { s.Headers[i].SMTPId = s.Id err := db.Save(&s.Headers[i]).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } } @@ -228,12 +229,12 @@ func DeleteSMTP(id int64, uid int64) error { // Delete all custom headers err = db.Where("smtp_id=?", id).Delete(&Header{}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } err = db.Where("user_id=?", uid).Delete(SMTP{Id: id}).Error if err != nil { - Logger.Println(err) + log.Error(err) } return err } diff --git a/models/template.go b/models/template.go index dbb24dc0..8d71c789 100644 --- a/models/template.go +++ b/models/template.go @@ -6,6 +6,7 @@ import ( "html/template" "time" + log "github.com/gophish/gophish/logger" "github.com/jinzhu/gorm" ) @@ -78,7 +79,7 @@ func GetTemplates(uid int64) ([]Template, error) { ts := []Template{} err := db.Where("user_id=?", uid).Find(&ts).Error if err != nil { - Logger.Println(err) + log.Error(err) return ts, err } for i, _ := range ts { @@ -88,7 +89,7 @@ func GetTemplates(uid int64) ([]Template, error) { ts[i].Attachments = make([]Attachment, 0) } if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return ts, err } } @@ -100,14 +101,14 @@ func GetTemplate(id int64, uid int64) (Template, error) { t := Template{} err := db.Where("user_id=? and id=?", uid, id).Find(&t).Error if err != nil { - Logger.Println(err) + log.Error(err) return t, err } // Get Attachments err = db.Where("template_id=?", t.Id).Find(&t.Attachments).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return t, err } if err == nil && len(t.Attachments) == 0 { @@ -121,14 +122,14 @@ func GetTemplateByName(n string, uid int64) (Template, error) { t := Template{} err := db.Where("user_id=? and name=?", uid, n).Find(&t).Error if err != nil { - Logger.Println(err) + log.Error(err) return t, err } // Get Attachments err = db.Where("template_id=?", t.Id).Find(&t.Attachments).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return t, err } if err == nil && len(t.Attachments) == 0 { @@ -145,17 +146,16 @@ func PostTemplate(t *Template) error { } err = db.Save(t).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } // Save every attachment - for i, _ := range t.Attachments { - Logger.Println(t.Attachments[i].Name) + for i := range t.Attachments { t.Attachments[i].TemplateId = t.Id err := db.Save(&t.Attachments[i]).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } } @@ -171,7 +171,7 @@ func PutTemplate(t *Template) error { // Delete all attachments, and replace with new ones err = db.Where("template_id=?", t.Id).Delete(&Attachment{}).Error if err != nil && err != gorm.ErrRecordNotFound { - Logger.Println(err) + log.Error(err) return err } if err == gorm.ErrRecordNotFound { @@ -181,7 +181,7 @@ func PutTemplate(t *Template) error { t.Attachments[i].TemplateId = t.Id err := db.Save(&t.Attachments[i]).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } } @@ -189,7 +189,7 @@ func PutTemplate(t *Template) error { // Save final template err = db.Where("id=?", t.Id).Save(t).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } return nil @@ -201,14 +201,14 @@ func DeleteTemplate(id int64, uid int64) error { // Delete attachments err := db.Where("template_id=?", id).Delete(&Attachment{}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } // Finally, delete the template itself err = db.Where("user_id=?", uid).Delete(Template{Id: id}).Error if err != nil { - Logger.Println(err) + log.Error(err) return err } return nil diff --git a/util/util.go b/util/util.go index 2285e15d..f0ffb0b9 100644 --- a/util/util.go +++ b/util/util.go @@ -11,20 +11,17 @@ import ( "fmt" "io" "io/ioutil" - "log" "math/big" "net/http" "net/mail" "os" "time" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/models" "github.com/jordan-wright/email" ) -// Logger is used to send logging messages to stdout. -var Logger = log.New(os.Stdout, " ", log.Ldate|log.Ltime|log.Lshortfile) - // ParseMail takes in an HTTP Request and returns an Email object // TODO: This function will likely be changed to take in a []byte func ParseMail(r *http.Request) (email.Email, error) { @@ -124,7 +121,7 @@ func CheckAndCreateSSL(cp string, kp string) error { return nil } - Logger.Printf("Creating new self-signed certificates for administration interface...\n") + log.Infof("Creating new self-signed certificates for administration interface") priv, err := ecdsa.GenerateKey(elliptic.P384(), rand.Reader) @@ -177,6 +174,6 @@ func CheckAndCreateSSL(cp string, kp string) error { pem.Encode(keyOut, &pem.Block{Type: "EC PRIVATE KEY", Bytes: b}) keyOut.Close() - Logger.Println("TLS Certificate Generation complete") + log.Info("TLS Certificate Generation complete") return nil } diff --git a/worker/worker.go b/worker/worker.go index acfae0f2..5b918443 100644 --- a/worker/worker.go +++ b/worker/worker.go @@ -1,17 +1,14 @@ package worker import ( - "log" - "os" "time" + log "github.com/gophish/gophish/logger" "github.com/gophish/gophish/mailer" "github.com/gophish/gophish/models" + "github.com/sirupsen/logrus" ) -// Logger is the logger for the worker -var Logger = log.New(os.Stdout, " ", log.Ldate|log.Ltime|log.Lshortfile) - // Worker is the background worker that handles watching for new campaigns and sending emails appropriately. type Worker struct{} @@ -23,17 +20,17 @@ func New() *Worker { // Start launches the worker to poll the database every minute for any pending maillogs // that need to be processed. func (w *Worker) Start() { - Logger.Println("Background Worker Started Successfully - Waiting for Campaigns") + log.Info("Background Worker Started Successfully - Waiting for Campaigns") for t := range time.Tick(1 * time.Minute) { ms, err := models.GetQueuedMailLogs(t.UTC()) if err != nil { - Logger.Println(err) + log.Error(err) continue } // Lock the MailLogs (they will be unlocked after processing) err = models.LockMailLogs(ms, true) if err != nil { - Logger.Println(err) + log.Error(err) continue } // We'll group the maillogs by campaign ID to (sort of) group @@ -51,18 +48,20 @@ func (w *Worker) Start() { uid := msc[0].(*models.MailLog).UserId c, err := models.GetCampaign(cid, uid) if err != nil { - Logger.Println(err) + log.Error(err) errorMail(err, msc) return } if c.Status == models.CAMPAIGN_QUEUED { err := c.UpdateStatus(models.CAMPAIGN_IN_PROGRESS) if err != nil { - Logger.Println(err) + log.Error(err) return } } - Logger.Printf("Sending %d maillogs to Mailer", len(msc)) + log.WithFields(logrus.Fields{ + "num_emails": len(msc), + }).Info("Sending emails to mailer for processing") mailer.Mailer.Queue <- msc }(cid, msc) } @@ -73,7 +72,7 @@ func (w *Worker) Start() { func (w *Worker) LaunchCampaign(c models.Campaign) { ms, err := models.GetMailLogsByCampaign(c.Id) if err != nil { - Logger.Println(err) + log.Error(err) return } models.LockMailLogs(ms, true)