Expand log functionality (#58)

Fixes #21
- Re-opens log files on SIGHUP (creates a new file if doesn't exists, otherwise open in append mode)
- Ability to change log file / destination via config, and apply those changes by signaling SIGHUP
- Ability to change log level via config, and apply by signaling SIGHUP

Other changes:
- fixes #68
- guerrilla-redis-db more robust (uses go-mysql-driver, fix sync.Pool)
- refactored enhanced codes to use 'static' variables
- optimized response to be written directly to client.bufout
- limited logrus imports

README.md

@@ -215,50 +215,51 @@ Copy goguerrilla.conf.sample to goguerrilla.conf
     {
         "allowed_hosts": ["guerrillamail.com","guerrillamailblock.com","sharklasers.com","guerrillamail.net","guerrillamail.org"], // What hosts to accept
         "pid_file" : "/var/run/go-guerrilla.pid", // pid = process id, so that other programs can send signals to our server
-                "backend_name": "guerrilla-db-redis", // what backend to use for saving email. See /backends dir
-                "backend_config" :
-                    {
-                        "mysql_db":"gmail_mail",
-                        "mysql_host":"127.0.0.1:3306",
-                        "mysql_pass":"ok",
-                        "mysql_user":"root",
-                        "mail_table":"new_mail",
-                        "redis_interface" : "127.0.0.1:6379",
-                        "redis_expire_seconds" : 7200,
-                        "save_workers_size" : 3,
-                        "primary_mail_host":"sharklasers.com"
-                    },
-                "servers" : [ // the following is an array of objects, each object represents a new server that will be spawned
-                    {
-                        "is_enabled" : true, // boolean
-                        "host_name":"mail.test.com", // the hostname of the server as set by MX record
-                        "max_size": 1000000, // maximum size of an email in bytes
-                        "private_key_file":"/path/to/pem/file/test.com.key",  // full path to pem file private key
-                        "public_key_file":"/path/to/pem/file/test.com.crt", // full path to pem file certificate
-                        "timeout":180, // timeout in number of seconds before an idle connection is closed
-                        "listen_interface":"127.0.0.1:25", // listen on ip and port
-                        "start_tls_on":true, // supports the STARTTLS command?
-                        "tls_always_on":false, // always connect using TLS? If true, start_tls_on will be false
-                        "max_clients": 1000, // max clients at one time
-                        "log_file":"/dev/stdout" // where to log to (currently ignored)
-                    },
-                    // the following is a second server, but listening on port 465 and always using TLS
-                    {
-                        "is_enabled" : true,
-                        "host_name":"mail.test.com",
-                        "max_size":1000000,
-                        "private_key_file":"/path/to/pem/file/test.com.key",
-                        "public_key_file":"/path/to/pem/file/test.com.crt",
-                        "timeout":180,
-                        "listen_interface":"127.0.0.1:465",
-                        "start_tls_on":false,
-                        "tls_always_on":true,
-                        "max_clients":500,
-                        "log_file":"/dev/stdout"
-                    }
-                    // repeat as many servers as you need
-                ]
+        "log_file" : "stderr", // can be "off", "stderr", "stdout" or any path to a file
+        "log_level" : "info", // can be  "debug", "info", "error", "warn", "fatal", "panic"
+        "backend_name": "guerrilla-db-redis", // what backend to use for saving email. See /backends dir
+        "backend_config" :
+            {
+                "mysql_db":"gmail_mail",
+                "mysql_host":"127.0.0.1:3306",
+                "mysql_pass":"ok",
+                "mysql_user":"root",
+                "mail_table":"new_mail",
+                "redis_interface" : "127.0.0.1:6379",
+                "redis_expire_seconds" : 7200,
+                "save_workers_size" : 3,
+                "primary_mail_host":"sharklasers.com"
+            },
+        "servers" : [ // the following is an array of objects, each object represents a new server that will be spawned
+            {
+                "is_enabled" : true, // boolean
+                "host_name":"mail.test.com", // the hostname of the server as set by MX record
+                "max_size": 1000000, // maximum size of an email in bytes
+                "private_key_file":"/path/to/pem/file/test.com.key",  // full path to pem file private key
+                "public_key_file":"/path/to/pem/file/test.com.crt", // full path to pem file certificate
+                "timeout":180, // timeout in number of seconds before an idle connection is closed
+                "listen_interface":"127.0.0.1:25", // listen on ip and port
+                "start_tls_on":true, // supports the STARTTLS command?
+                "tls_always_on":false, // always connect using TLS? If true, start_tls_on will be false
+                "max_clients": 1000, // max clients at one time
+                "log_file":"/dev/stdout" // optional. Can be "off", "stderr", "stdout" or any path to a file. Will use global setting of empty.
+            },
+            // the following is a second server, but listening on port 465 and always using TLS
+            {
+                "is_enabled" : true,
+                "host_name":"mail.test.com",
+                "max_size":1000000,
+                "private_key_file":"/path/to/pem/file/test.com.key",
+                "public_key_file":"/path/to/pem/file/test.com.crt",
+                "timeout":180,
+                "listen_interface":"127.0.0.1:465",
+                "start_tls_on":false,
+                "tls_always_on":true,
+                "max_clients":500
             }
+            // repeat as many servers as you need
+        ]
+    }
     }
 
 The Json parser is very strict on syntax. If there's a parse error and it

backends/abstract.go

@@ -1,8 +1,6 @@
 package backends
 
 import (
-	log "github.com/Sirupsen/logrus"
-
 	"errors"
 	"fmt"
 	"github.com/flashmob/go-guerrilla/envelope"
@@ -60,8 +58,8 @@ func (b *AbstractBackend) Process(mail *envelope.Envelope) BackendResult {
 	mail.ParseHeaders()
 
 	if b.config.LogReceivedMails {
-		log.Infof("Mail from: %s / to: %v", mail.MailFrom.String(), mail.RcptTo)
-		log.Info("Headers are: %s", mail.Header)
+		mainlog.Infof("Mail from: %s / to: %v", mail.MailFrom.String(), mail.RcptTo)
+		mainlog.Info("Headers are: %s", mail.Header)
 
 	}
 	return NewBackendResult("250 OK")
@@ -84,7 +82,7 @@ func (b *AbstractBackend) saveMailWorker(saveMailChan chan *savePayload) {
 	for {
 		payload := <-saveMailChan
 		if payload == nil {
-			log.Debug("No more saveMailChan payload")
+			mainlog.Debug("No more saveMailChan payload")
 			return
 		}
 		// process the email here

backends/backend.go

@@ -8,11 +8,13 @@ import (
 	"sync"
 	"time"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/flashmob/go-guerrilla/envelope"
+	"github.com/flashmob/go-guerrilla/log"
 	"github.com/flashmob/go-guerrilla/response"
 )
 
+var mainlog log.Logger
+
 // Backends process received mail. Depending on the implementation, they can store mail in the database,
 // write to a file, check for spam, re-transmit to another server, etc.
 // Must return an SMTP message (i.e. "250 OK") and a boolean indicating
@@ -33,10 +35,6 @@ type Backend interface {
 	loadConfig(BackendConfig) error
 }
 
-type configLoader interface {
-	loadConfig(backendConfig BackendConfig) (err error)
-}
-
 type BackendConfig map[string]interface{}
 
 var backends = map[string]Backend{}
@@ -101,7 +99,7 @@ type BackendGateway struct {
 	b  Backend
 	// controls access to state
 	stateGuard sync.Mutex
-	State      int
+	State      backendState
 	config     BackendConfig
 }
 
@@ -112,10 +110,17 @@ const (
 	BackendStateError
 )
 
+type backendState int
+
+func (s backendState) String() string {
+	return strconv.Itoa(int(s))
+}
+
 // New retrieve a backend specified by the backendName, and initialize it using
 // backendConfig
-func New(backendName string, backendConfig BackendConfig) (Backend, error) {
+func New(backendName string, backendConfig BackendConfig, l log.Logger) (Backend, error) {
 	backend, found := backends[backendName]
+	mainlog = l
 	if !found {
 		return nil, fmt.Errorf("backend %q not found", backendName)
 	}
@@ -131,13 +136,7 @@ func New(backendName string, backendConfig BackendConfig) (Backend, error) {
 // Process distributes an envelope to one of the backend workers
 func (gw *BackendGateway) Process(e *envelope.Envelope) BackendResult {
 	if gw.State != BackendStateRunning {
-		resp := &response.Response{
-			EnhancedCode: response.OtherOrUndefinedProtocolStatus,
-			BasicCode:    554,
-			Class:        response.ClassPermanentFailure,
-			Comment:      "Transaction failed - backend not running " + strconv.Itoa(gw.State),
-		}
-		return NewBackendResult(resp.String())
+		return NewBackendResult(response.Canned.FailBackendNotRunning + gw.State.String())
 	}
 
 	to := e.RcptTo
@@ -152,31 +151,13 @@ func (gw *BackendGateway) Process(e *envelope.Envelope) BackendResult {
 	select {
 	case status := <-savedNotify:
 		if status.err != nil {
-			resp := &response.Response{
-				EnhancedCode: response.OtherOrUndefinedProtocolStatus,
-				BasicCode:    554,
-				Class:        response.ClassPermanentFailure,
-				Comment:      "Error: " + status.err.Error(),
-			}
-			return NewBackendResult(resp.String())
+			return NewBackendResult(response.Canned.FailBackendTransaction + status.err.Error())
 		}
-		resp := &response.Response{
-			EnhancedCode: response.OtherStatus,
-			BasicCode:    250,
-			Class:        response.ClassSuccess,
-			Comment:      fmt.Sprintf("OK : queued as %s", status.hash),
-		}
-		return NewBackendResult(resp.String())
+		return NewBackendResult(response.Canned.SuccessMessageQueued + status.hash)
 
 	case <-time.After(time.Second * 30):
-		log.Infof("Backend has timed out")
-		resp := &response.Response{
-			EnhancedCode: response.OtherOrUndefinedProtocolStatus,
-			BasicCode:    554,
-			Class:        response.ClassPermanentFailure,
-			Comment:      "Error: transaction timeout",
-		}
-		return NewBackendResult(resp.String())
+		mainlog.Infof("Backend has timed out")
+		return NewBackendResult(response.Canned.FailBackendTimeout)
 	}
 }
 func (gw *BackendGateway) Shutdown() error {

backends/guerrilla_db_redis.go

@@ -6,6 +6,12 @@ package backends
 // A lot of email gets discarded without viewing on Guerrilla Mail,
 // so it's much faster to put in Redis, where other programs can
 // process it later, without touching the disk.
+//
+// Some features:
+// - It batches the SQL inserts into a single query and inserts either after a time threshold or if the batch is full
+// - If the mysql driver crashes, it's able to recover, log the incident and resume again.
+// - It also does a clean shutdown - it tries to save everything before returning
+//
 // Short history:
 // Started with issuing an insert query for each single email and another query to update the tally
 // Then applied the following optimizations:
@@ -13,25 +19,29 @@ package backends
 // - Changed the MySQL queries to insert in batch
 // - Made a Compressor that recycles buffers using sync.Pool
 // The result was around 400% speed improvement. If you know of any more improvements, please share!
+// - Added the recovery mechanisi,
+
 import (
 	"fmt"
 
 	"time"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/garyburd/redigo/redis"
 
 	"bytes"
 	"compress/zlib"
-	"github.com/flashmob/go-guerrilla/envelope"
-	"github.com/ziutek/mymysql/autorc"
-	_ "github.com/ziutek/mymysql/godrv"
+	"database/sql"
+	_ "github.com/go-sql-driver/mysql"
+
+	"github.com/go-sql-driver/mysql"
 	"io"
+	"runtime/debug"
+	"strings"
 	"sync"
 )
 
 // how many rows to batch at a time
-const GuerrillaDBAndRedisBatchMax = 500
+const GuerrillaDBAndRedisBatchMax = 2
 
 // tick on every...
 const GuerrillaDBAndRedisBatchTimeout = time.Second * 3
@@ -50,7 +60,7 @@ type GuerrillaDBAndRedisBackend struct {
 }
 
 // statement cache. It's an array, not slice
-type stmtCache [GuerrillaDBAndRedisBatchMax]*autorc.Stmt
+type stmtCache [GuerrillaDBAndRedisBatchMax]*sql.Stmt
 
 type guerrillaDBAndRedisConfig struct {
 	NumberOfWorkers    int    `json:"save_workers_size"`
@@ -86,15 +96,6 @@ func (g *GuerrillaDBAndRedisBackend) getNumberOfWorkers() int {
 	return g.config.NumberOfWorkers
 }
 
-func (g *GuerrillaDBAndRedisBackend) Process(mail *envelope.Envelope) BackendResult {
-	to := mail.RcptTo
-	log.Info("(g *GuerrillaDBAndRedisBackend) Process called")
-	if len(to) == 0 {
-		return NewBackendResult("554 Error: no recipient")
-	}
-	return nil
-}
-
 type redisClient struct {
 	isConnected bool
 	conn        redis.Conn
@@ -105,7 +106,7 @@ type redisClient struct {
 type compressedData struct {
 	extraHeaders []byte
 	data         *bytes.Buffer
-	pool         sync.Pool
+	pool         *sync.Pool
 }
 
 // newCompressedData returns a new CompressedData
@@ -117,7 +118,7 @@ func newCompressedData() *compressedData {
 		},
 	}
 	return &compressedData{
-		pool: p,
+		pool: &p,
 	}
 }
 
@@ -156,40 +157,66 @@ func (c *compressedData) clear() {
 }
 
 // prepares the sql query with the number of rows that can be batched with it
-func (g *GuerrillaDBAndRedisBackend) prepareInsertQuery(rows int, db *autorc.Conn) *autorc.Stmt {
+func (g *GuerrillaDBAndRedisBackend) prepareInsertQuery(rows int, db *sql.DB) *sql.Stmt {
 	if rows == 0 {
 		panic("rows argument cannot be 0")
 	}
 	if g.cache[rows-1] != nil {
 		return g.cache[rows-1]
 	}
-	sql := "INSERT INTO " + g.config.MysqlTable + " "
-	sql += "(`date`, `to`, `from`, `subject`, `body`, `charset`, `mail`, `spam_score`, `hash`, `content_type`, `recipient`, `has_attach`, `ip_addr`, `return_path`, `is_tls`)"
-	sql += " values "
+	sqlstr := "INSERT INTO " + g.config.MysqlTable + " "
+	sqlstr += "(`date`, `to`, `from`, `subject`, `body`, `charset`, `mail`, `spam_score`, `hash`, `content_type`, `recipient`, `has_attach`, `ip_addr`, `return_path`, `is_tls`)"
+	sqlstr += " values "
 	values := "(NOW(), ?, ?, ?, ? , 'UTF-8' , ?, 0, ?, '', ?, 0, ?, ?, ?)"
 	// add more rows
 	comma := ""
 	for i := 0; i < rows; i++ {
-		sql += comma + values
+		sqlstr += comma + values
 		if comma == "" {
 			comma = ","
 		}
 	}
-	//log.Debug("Prepared SQL", rows, sql)
-	stmt, sqlErr := db.Prepare(sql)
+	stmt, sqlErr := db.Prepare(sqlstr)
 	if sqlErr != nil {
-		log.WithError(sqlErr).Fatalf("failed while db.Prepare(INSERT...)")
+		mainlog.WithError(sqlErr).Fatalf("failed while db.Prepare(INSERT...)")
 	}
 	// cache it
 	g.cache[rows-1] = stmt
 	return stmt
 }
 
+func (g *GuerrillaDBAndRedisBackend) doQuery(c int, db *sql.DB, insertStmt *sql.Stmt, vals *[]interface{}) {
+	var execErr error
+	defer func() {
+		if r := recover(); r != nil {
+			//logln(1, fmt.Sprintf("Recovered in %v", r))
+			mainlog.Error("Recovered form panic:", r, string(debug.Stack()))
+			sum := 0
+			for _, v := range *vals {
+				if str, ok := v.(string); ok {
+					sum = sum + len(str)
+				}
+			}
+			mainlog.Errorf("panic while inserting query [%s] size:%d, err %v", r, sum, execErr)
+			panic("query failed")
+		}
+	}()
+	// prepare the query used to insert when rows reaches batchMax
+	insertStmt = g.prepareInsertQuery(c, db)
+	_, execErr = insertStmt.Exec(*vals...)
+	if execErr != nil {
+		mainlog.WithError(execErr).Error("There was a problem the insert")
+	}
+}
+
 // Batches the rows from the feeder chan in to a single INSERT statement.
 // Execute the batches query when:
 // - number of batched rows reaches a threshold, i.e. count n = threshold
 // - or, no new rows within a certain time, i.e. times out
-func (g *GuerrillaDBAndRedisBackend) insertQueryBatcher(feeder chan []interface{}, db *autorc.Conn) {
+// The goroutine can either exit if there's a panic or feeder channel closes
+// it returns feederOk which signals if the feeder chanel was ok (still open) while returning
+// if it feederOk is false, then it means the feeder chanel is closed
+func (g *GuerrillaDBAndRedisBackend) insertQueryBatcher(feeder chan []interface{}, db *sql.DB) (feederOk bool) {
 	// controls shutdown
 	defer g.batcherWg.Done()
 	g.batcherWg.Add(1)
@@ -205,35 +232,34 @@ func (g *GuerrillaDBAndRedisBackend) insertQueryBatcher(feeder chan []interface{
 	// inserts executes a batched insert query, clears the vals and resets the count
 	insert := func(c int) {
 		if c > 0 {
-			insertStmt = g.prepareInsertQuery(c, db)
-			insertStmt.Bind(vals...)
-			_, _, err := insertStmt.Exec()
-			if err != nil {
-				log.WithError(err).Error("There was a problem the insert")
-			} else {
-				//log.Debugf("Inserted %d rows ", count)
-			}
+			g.doQuery(c, db, insertStmt, &vals)
 		}
 		vals = nil
 		count = 0
 	}
+	defer func() {
+		if r := recover(); r != nil {
+			mainlog.Error("insertQueryBatcher caught a panic", r)
+		}
+	}()
 	// Keep getting values from feeder and add to batch.
 	// if feeder times out, execute the batched query
 	// otherwise, execute the batched query once it reaches the GuerrillaDBAndRedisBatchMax threshold
+	feederOk = true
 	for {
 		select {
-		case row := <-feeder:
-			log.Info("row form chan is", row, "cols:", len(row))
+		// it may panic when reading on a closed feeder channel. feederOK detects if it was closed
+		case row, feederOk := <-feeder:
 			if row == nil {
-				log.Debug("Query batchaer exiting")
+				mainlog.Info("Query batchaer exiting")
 				// Insert any remaining rows
 				insert(count)
-				return
+				return feederOk
 			}
 			vals = append(vals, row...)
 			count++
-			//log.Debug("apend vals", count, vals)
-			if count == GuerrillaDBAndRedisBatchMax {
+			mainlog.Debug("new feeder row:", row, " cols:", len(row), " count:", count, " worker", workerId)
+			if count >= GuerrillaDBAndRedisBatchMax {
 				insert(GuerrillaDBAndRedisBatchMax)
 			}
 			// stop timer from firing (reset the interrupt)
@@ -242,8 +268,6 @@ func (g *GuerrillaDBAndRedisBackend) insertQueryBatcher(feeder chan []interface{
 			}
 			t.Reset(GuerrillaDBAndRedisBatchTimeout)
 		case <-t.C:
-			//log.Debugf("Query batcher timer fired! [%d]", len(vals))
-			//log.Debug("Contents:", count, vals)
 			// anything to insert?
 			if n := len(vals); n > 0 {
 				insert(count)
@@ -253,36 +277,73 @@ func (g *GuerrillaDBAndRedisBackend) insertQueryBatcher(feeder chan []interface{
 	}
 }
 
+func trimToLimit(str string, limit int) string {
+	ret := strings.TrimSpace(str)
+	if len(str) > limit {
+		ret = str[:limit]
+	}
+	return ret
+}
+
+var workerId = 0
+
+func (g *GuerrillaDBAndRedisBackend) mysqlConnect() (*sql.DB, error) {
+	conf := mysql.Config{
+		User:         g.config.MysqlUser,
+		Passwd:       g.config.MysqlPass,
+		DBName:       g.config.MysqlDB,
+		Net:          "tcp",
+		Addr:         g.config.MysqlHost,
+		ReadTimeout:  GuerrillaDBAndRedisBatchTimeout + (time.Second * 10),
+		WriteTimeout: GuerrillaDBAndRedisBatchTimeout + (time.Second * 10),
+		Params:       map[string]string{"collation": "utf8_general_ci"},
+	}
+	if db, err := sql.Open("mysql", conf.FormatDSN()); err != nil {
+		mainlog.Error("cannot open mysql", err)
+		return nil, err
+	} else {
+		return db, nil
+	}
+
+}
+
 func (g *GuerrillaDBAndRedisBackend) saveMailWorker(saveMailChan chan *savePayload) {
 	var to, body string
-	//var length int
-	//var err error
 
 	var redisErr error
 
+	workerId++
+
 	redisClient := &redisClient{}
-	db := autorc.New(
-		"tcp",
-		"",
-		g.config.MysqlHost,
-		g.config.MysqlUser,
-		g.config.MysqlPass,
-		g.config.MysqlDB)
-	db.Register("set names utf8")
+	var db *sql.DB
+	var err error
+	db, err = g.mysqlConnect()
+	if err != nil {
+		mainlog.Fatalf("cannot open mysql: %s", err)
+	}
+
 	// start the query SQL batching where we will send data via the feeder channel
 	feeder := make(chan []interface{}, 1)
-	go g.insertQueryBatcher(feeder, db)
+	go func() {
+		for {
+			if feederOK := g.insertQueryBatcher(feeder, db); !feederOK {
+				mainlog.Debug("insertQueryBatcher exited")
+				return
+			}
+			// if insertQueryBatcher panics, it can recover and go in again
+			mainlog.Debug("resuming insertQueryBatcher")
+		}
+
+	}()
 
 	defer func() {
 		if r := recover(); r != nil {
 			//recover form closed channel
-			fmt.Println("Recovered in f", r)
-		}
-		if db.Raw != nil {
-			db.Raw.Close()
+			mainlog.Error("panic recovered in saveMailWorker", r)
 		}
+		db.Close()
 		if redisClient.conn != nil {
-			log.Infof("closed redis")
+			mainlog.Infof("closed redis")
 			redisClient.conn.Close()
 		}
 		// close the feeder & wait for query batcher to exit.
@@ -297,11 +358,13 @@ func (g *GuerrillaDBAndRedisBackend) saveMailWorker(saveMailChan chan *savePaylo
 	for {
 		payload := <-saveMailChan
 		if payload == nil {
-			log.Debug("No more saveMailChan payload")
+			mainlog.Debug("No more saveMailChan payload")
 			return
 		}
-		to = payload.recipient.User + "@" + g.config.PrimaryHost
-
+		mainlog.Debug("Got mail from chan", payload.mail.RemoteAddress)
+		to = trimToLimit(strings.TrimSpace(payload.recipient.User)+"@"+g.config.PrimaryHost, 255)
+		payload.mail.Helo = trimToLimit(payload.mail.Helo, 255)
+		payload.recipient.Host = trimToLimit(payload.recipient.Host, 255)
 		ts := fmt.Sprintf("%d", time.Now().UnixNano())
 		payload.mail.ParseHeaders()
 		hash := MD5Hex(
@@ -328,26 +391,24 @@ func (g *GuerrillaDBAndRedisBackend) saveMailWorker(saveMailChan chan *savePaylo
 		if redisErr == nil {
 			_, doErr := redisClient.conn.Do("SETEX", hash, g.config.RedisExpireSeconds, data)
 			if doErr == nil {
-				//payload.mail.Data = ""
-				//payload.mail.Data.Reset()
 				body = "redis" // the backend system will know to look in redis for the message data
 				data.clear()   // blank
 			}
 		} else {
-			log.WithError(redisErr).Warn("Error while SETEX on redis")
+			mainlog.WithError(redisErr).Warn("Error while connecting redis")
 		}
 
 		vals = []interface{}{} // clear the vals
 		vals = append(vals,
-			to,
-			payload.mail.MailFrom.String(),
-			payload.mail.Subject,
+			trimToLimit(to, 255),
+			trimToLimit(payload.mail.MailFrom.String(), 255),
+			trimToLimit(payload.mail.Subject, 255),
 			body,
 			data.String(),
 			hash,
-			to,
+			trimToLimit(to, 255),
 			payload.mail.RemoteAddress,
-			payload.mail.MailFrom.String(),
+			trimToLimit(payload.mail.MailFrom.String(), 255),
 			payload.mail.TLS)
 		feeder <- vals
 		payload.savedNotify <- &saveStatus{nil, hash}
@@ -369,18 +430,13 @@ func (c *redisClient) redisConnection(redisInterface string) (err error) {
 
 // test database connection settings
 func (g *GuerrillaDBAndRedisBackend) testSettings() (err error) {
-	db := autorc.New(
-		"tcp",
-		"",
-		g.config.MysqlHost,
-		g.config.MysqlUser,
-		g.config.MysqlPass,
-		g.config.MysqlDB)
-
-	if mysqlErr := db.Raw.Connect(); mysqlErr != nil {
-		err = fmt.Errorf("MySql cannot connect, check your settings: %s", mysqlErr)
+
+	var db *sql.DB
+
+	if db, err = g.mysqlConnect(); err != nil {
+		err = fmt.Errorf("MySql cannot connect, check your settings: %s", err)
 	} else {
-		db.Raw.Close()
+		db.Close()
 	}
 
 	redisClient := &redisClient{}

client.go

@@ -2,9 +2,11 @@ package guerrilla
 
 import (
 	"bufio"
+	"bytes"
 	"crypto/tls"
-	log "github.com/Sirupsen/logrus"
+	"fmt"
 	"github.com/flashmob/go-guerrilla/envelope"
+	"github.com/flashmob/go-guerrilla/log"
 	"net"
 	"net/textproto"
 	"sync"
@@ -37,7 +39,7 @@ type client struct {
 	state        ClientState
 	messagesSent int
 	// Response to be written to the client
-	response   string
+	response   bytes.Buffer
 	conn       net.Conn
 	bufin      *smtpBufferedReader
 	bufout     *bufio.Writer
@@ -45,28 +47,63 @@ type client struct {
 	ar         *adjustableLimitedReader
 	// guards access to conn
 	connGuard sync.Mutex
+	log       log.Logger
 }
 
 // Allocate a new client
-func NewClient(conn net.Conn, clientID uint64) *client {
+func NewClient(conn net.Conn, clientID uint64, logger log.Logger) *client {
 	c := &client{
 		conn: conn,
 		Envelope: &envelope.Envelope{
-			RemoteAddress: conn.RemoteAddr().String(),
+			RemoteAddress: getRemoteAddr(conn),
 		},
 		ConnectedAt: time.Now(),
 		bufin:       newSMTPBufferedReader(conn),
 		bufout:      bufio.NewWriter(conn),
 		ID:          clientID,
+		log:         logger,
 	}
 	// used for reading the DATA state
 	c.smtpReader = textproto.NewReader(c.bufin.Reader)
 	return c
 }
 
-// Add a response to be written on the next turn
-func (c *client) responseAdd(r string) {
-	c.response = c.response + r + "\r\n"
+// setResponse adds a response to be written on the next turn
+func (c *client) sendResponse(r ...interface{}) {
+	c.bufout.Reset(c.conn)
+	if c.log.IsDebug() {
+		// us additional buffer so that we can log the response in debug mode only
+		c.response.Reset()
+	}
+	for _, item := range r {
+		switch v := item.(type) {
+		case string:
+			if _, err := c.bufout.WriteString(v); err != nil {
+				c.log.WithError(err).Error("could not write to c.bufout")
+			}
+			if c.log.IsDebug() {
+				c.response.WriteString(v)
+			}
+		case error:
+			if _, err := c.bufout.WriteString(v.Error()); err != nil {
+				c.log.WithError(err).Error("could not write to c.bufout")
+			}
+			if c.log.IsDebug() {
+				c.response.WriteString(v.Error())
+			}
+		case fmt.Stringer:
+			if _, err := c.bufout.WriteString(v.String()); err != nil {
+				c.log.WithError(err).Error("could not write to c.bufout")
+			}
+			if c.log.IsDebug() {
+				c.response.WriteString(v.String())
+			}
+		}
+	}
+	c.bufout.WriteString("\r\n")
+	if c.log.IsDebug() {
+		c.response.WriteString("\r\n")
+	}
 }
 
 // resetTransaction resets the SMTP transaction, ready for the next email (doesn't disconnect)
@@ -112,7 +149,7 @@ func (c *client) setTimeout(t time.Duration) {
 	}
 }
 
-// Closes a client connection, , goroutine safe
+// closeConn closes a client connection, , goroutine safe
 func (c *client) closeConn() {
 	defer c.connGuard.Unlock()
 	c.connGuard.Lock()
@@ -135,31 +172,40 @@ func (c *client) init(conn net.Conn, clientID uint64) {
 	c.ID = clientID
 	c.TLS = false
 	c.errors = 0
-	c.response = ""
 	c.Helo = ""
 	c.Header = nil
-	c.RemoteAddress = conn.RemoteAddr().String()
+	c.RemoteAddress = getRemoteAddr(conn)
+
 }
 
-// getId returns the client's unique ID
+// getID returns the client's unique ID
 func (c *client) getID() uint64 {
 	return c.ID
 }
 
-// Upgrades a client connection to TLS
-func (client *client) upgradeToTLS(tlsConfig *tls.Config) bool {
+// UpgradeToTLS upgrades a client connection to TLS
+func (client *client) upgradeToTLS(tlsConfig *tls.Config) error {
 	var tlsConn *tls.Conn
 	// load the config thread-safely
 	tlsConn = tls.Server(client.conn, tlsConfig)
+	// Call handshake here to get any handshake error before reading starts
 	err := tlsConn.Handshake()
 	if err != nil {
-		log.WithError(err).Warnf("[%s] Failed TLS handshake", client.RemoteAddress)
-		return false
+		return err
 	}
+	// convert tlsConn to net.Conn
 	client.conn = net.Conn(tlsConn)
 	client.bufout.Reset(client.conn)
 	client.bufin.Reset(client.conn)
 	client.TLS = true
+	return err
+}
 
-	return true
+func getRemoteAddr(conn net.Conn) string {
+	if addr, ok := conn.RemoteAddr().(*net.TCPAddr); ok {
+		// we just want the IP (not the port)
+		return addr.IP.String()
+	} else {
+		return conn.RemoteAddr().Network()
+	}
 }

cmd/guerrillad/root.go

@@ -1,7 +1,7 @@
 package main
 
 import (
-	log "github.com/Sirupsen/logrus"
+	"github.com/Sirupsen/logrus"
 	"github.com/spf13/cobra"
 )
 
@@ -23,9 +23,9 @@ func init() {
 		"print out more debug information")
 	rootCmd.PersistentPreRun = func(cmd *cobra.Command, args []string) {
 		if verbose {
-			log.SetLevel(log.DebugLevel)
+			logrus.SetLevel(logrus.DebugLevel)
 		} else {
-			log.SetLevel(log.InfoLevel)
+			logrus.SetLevel(logrus.InfoLevel)
 		}
 	}
 }

cmd/guerrillad/serve.go

@@ -4,20 +4,19 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
-	log "github.com/Sirupsen/logrus"
+	"github.com/flashmob/go-guerrilla"
+	"github.com/flashmob/go-guerrilla/backends"
+	"github.com/flashmob/go-guerrilla/log"
 	"github.com/spf13/cobra"
 	"io/ioutil"
 	"os"
 	"os/exec"
 	"os/signal"
+	"reflect"
 	"strconv"
 	"strings"
 	"syscall"
 	"time"
-
-	"github.com/flashmob/go-guerrilla"
-	"github.com/flashmob/go-guerrilla/backends"
-	"reflect"
 )
 
 const (
@@ -36,9 +35,15 @@ var (
 
 	cmdConfig     = CmdConfig{}
 	signalChannel = make(chan os.Signal, 1) // for trapping SIG_HUP
+	mainlog       log.Logger
 )
 
 func init() {
+	// log to stderr on startup
+	var logOpenError error
+	if mainlog, logOpenError = log.GetLogger(log.OutputStderr.String()); logOpenError != nil {
+		mainlog.WithError(logOpenError).Errorf("Failed creating a logger to %s", log.OutputStderr)
+	}
 	serveCmd.PersistentFlags().StringVarP(&configPath, "config", "c",
 		"goguerrilla.conf", "Path to the configuration file")
 	// intentionally didn't specify default pidFile; value from config is used if flag is empty
@@ -59,19 +64,19 @@ func sigHandler(app guerrilla.Guerrilla) {
 			newConfig := CmdConfig{}
 			err := readConfig(configPath, pidFile, &newConfig)
 			if err != nil {
-				log.WithError(err).Error("Error while ReadConfig (reload)")
+				mainlog.WithError(err).Error("Error while ReadConfig (reload)")
 			} else {
 				cmdConfig = newConfig
-				log.Infof("Configuration was reloaded at %s", guerrilla.ConfigLoadTime)
+				mainlog.Infof("Configuration was reloaded at %s", guerrilla.ConfigLoadTime)
 				cmdConfig.emitChangeEvents(&oldConfig, app)
 			}
 		} else if sig == syscall.SIGTERM || sig == syscall.SIGQUIT || sig == syscall.SIGINT {
-			log.Infof("Shutdown signal caught")
+			mainlog.Infof("Shutdown signal caught")
 			app.Shutdown()
-			log.Infof("Shutdown completd, exiting.")
+			mainlog.Infof("Shutdown completed, exiting.")
 			return
 		} else {
-			log.Infof("Shutdown, unknown signal caught")
+			mainlog.Infof("Shutdown, unknown signal caught")
 			return
 		}
 	}
@@ -80,17 +85,18 @@ func sigHandler(app guerrilla.Guerrilla) {
 func subscribeBackendEvent(event string, backend backends.Backend, app guerrilla.Guerrilla) {
 
 	app.Subscribe(event, func(cmdConfig *CmdConfig) {
+		logger, _ := log.GetLogger(cmdConfig.LogFile)
 		var err error
 		if err = backend.Shutdown(); err != nil {
-			log.WithError(err).Warn("Backend failed to shutdown")
+			logger.WithError(err).Warn("Backend failed to shutdown")
 			return
 		}
-		backend, err = backends.New(cmdConfig.BackendName, cmdConfig.BackendConfig)
+		backend, err = backends.New(cmdConfig.BackendName, cmdConfig.BackendConfig, logger)
 		if err != nil {
-			log.WithError(err).Fatalf("Error while loading the backend %q",
+			logger.WithError(err).Fatalf("Error while loading the backend %q",
 				cmdConfig.BackendName)
 		} else {
-			log.Info("Backend started:", cmdConfig.BackendName)
+			logger.Info("Backend started:", cmdConfig.BackendName)
 		}
 	})
 }
@@ -100,7 +106,7 @@ func serve(cmd *cobra.Command, args []string) {
 
 	err := readConfig(configPath, pidFile, &cmdConfig)
 	if err != nil {
-		log.WithError(err).Fatal("Error while reading config")
+		mainlog.WithError(err).Fatal("Error while reading config")
 	}
 
 	// Check that max clients is not greater than system open file limit.
@@ -112,26 +118,28 @@ func serve(cmd *cobra.Command, args []string) {
 			maxClients += s.MaxClients
 		}
 		if maxClients > fileLimit {
-			log.Fatalf("Combined max clients for all servers (%d) is greater than open file limit (%d). "+
+			mainlog.Fatalf("Combined max clients for all servers (%d) is greater than open file limit (%d). "+
 				"Please increase your open file limit or decrease max clients.", maxClients, fileLimit)
 		}
 	}
 
 	// Backend setup
 	var backend backends.Backend
-	backend, err = backends.New(cmdConfig.BackendName, cmdConfig.BackendConfig)
+	backend, err = backends.New(cmdConfig.BackendName, cmdConfig.BackendConfig, mainlog)
 	if err != nil {
-		log.WithError(err).Fatalf("Error while loading the backend %q",
+		mainlog.WithError(err).Fatalf("Error while loading the backend %q",
 			cmdConfig.BackendName)
 	}
 
-	app, err := guerrilla.New(&cmdConfig.AppConfig, backend)
+	app, err := guerrilla.New(&cmdConfig.AppConfig, backend, mainlog)
 	if err != nil {
-		log.WithError(err).Error("Error(s) when creating new server(s)")
+		mainlog.WithError(err).Error("Error(s) when creating new server(s)")
 	}
+
+	// start the app
 	err = app.Start()
 	if err != nil {
-		log.WithError(err).Error("Error(s) when starting server(s)")
+		mainlog.WithError(err).Error("Error(s) when starting server(s)")
 	}
 	subscribeBackendEvent("config_change:backend_config", backend, app)
 	subscribeBackendEvent("config_change:backend_name", backend, app)
@@ -141,6 +149,13 @@ func serve(cmd *cobra.Command, args []string) {
 	app.Subscribe("config_change:pid_file", func(ac *guerrilla.AppConfig) {
 		writePid(ac.PidFile)
 	})
+	// change the logger from stdrerr to one from config
+	mainlog.Infof("main log configured to %s", cmdConfig.LogFile)
+	var logOpenError error
+	if mainlog, logOpenError = log.GetLogger(cmdConfig.LogFile); logOpenError != nil {
+		mainlog.WithError(logOpenError).Errorf("Failed changing to a custom logger [%s]", cmdConfig.LogFile)
+	}
+	app.SetLogger(mainlog)
 	sigHandler(app)
 
 }
@@ -218,12 +233,12 @@ func writePid(pidFile string) {
 			pid := os.Getpid()
 			if _, err := f.WriteString(fmt.Sprintf("%d", pid)); err == nil {
 				f.Sync()
-				log.Infof("pid_file (%s) written with pid:%v", pidFile, pid)
+				mainlog.Infof("pid_file (%s) written with pid:%v", pidFile, pid)
 			} else {
-				log.WithError(err).Fatalf("Error while writing pidFile (%s)", pidFile)
+				mainlog.WithError(err).Fatalf("Error while writing pidFile (%s)", pidFile)
 			}
 		} else {
-			log.WithError(err).Fatalf("Error while creating pidFile (%s)", pidFile)
+			mainlog.WithError(err).Fatalf("Error while creating pidFile (%s)", pidFile)
 		}
 	}
 }

cmd/guerrillad/serve_test.go

@@ -1,8 +1,6 @@
 package main
 
 import (
-	"bufio"
-	"bytes"
 	"crypto/tls"
 	"encoding/json"
 	"io/ioutil"
@@ -15,9 +13,9 @@ import (
 	"testing"
 	"time"
 
-	log "github.com/Sirupsen/logrus"
 	"github.com/flashmob/go-guerrilla"
 	"github.com/flashmob/go-guerrilla/backends"
+	"github.com/flashmob/go-guerrilla/log"
 	test "github.com/flashmob/go-guerrilla/tests"
 	"github.com/flashmob/go-guerrilla/tests/testcert"
 	"github.com/spf13/cobra"
@@ -25,6 +23,8 @@ import (
 
 var configJsonA = `
 {
+    "log_file" : "../../tests/testlog",
+    "log_level" : "debug",
     "pid_file" : "./pidfile.pid",
     "allowed_hosts": [
       "guerrillamail.com",
@@ -48,7 +48,8 @@ var configJsonA = `
             "listen_interface":"127.0.0.1:25",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 1000
+            "max_clients": 1000,
+            "log_file" : "../../tests/testlog"
         },
         {
             "is_enabled" : false,
@@ -60,7 +61,8 @@ var configJsonA = `
             "listen_interface":"127.0.0.1:2228",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 1000
+            "max_clients": 1000,
+            "log_file" : "../../tests/testlog"
         }
     ]
 }
@@ -69,7 +71,9 @@ var configJsonA = `
 // backend config changed, log_received_mails is false
 var configJsonB = `
 {
-"pid_file" : "./pidfile2.pid",
+    "log_file" : "../../tests/testlog",
+    "log_level" : "debug",
+    "pid_file" : "./pidfile2.pid",
     "allowed_hosts": [
       "guerrillamail.com",
       "guerrillamailblock.com",
@@ -92,7 +96,8 @@ var configJsonB = `
             "listen_interface":"127.0.0.1:25",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 1000
+            "max_clients": 1000,
+            "log_file" : "../../tests/testlog"
         }
     ]
 }
@@ -101,7 +106,9 @@ var configJsonB = `
 // backend_name changed, is guerrilla-redis-db + added a server
 var configJsonC = `
 {
-"pid_file" : "./pidfile.pid",
+    "log_file" : "../../tests/testlog",
+    "log_level" : "debug",
+    "pid_file" : "./pidfile.pid",
     "allowed_hosts": [
       "guerrillamail.com",
       "guerrillamailblock.com",
@@ -133,7 +140,8 @@ var configJsonC = `
             "listen_interface":"127.0.0.1:25",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 1000
+            "max_clients": 1000,
+            "log_file" : "../../tests/testlog"
         },
         {
             "is_enabled" : true,
@@ -145,7 +153,8 @@ var configJsonC = `
             "listen_interface":"127.0.0.1:465",
             "start_tls_on":false,
             "tls_always_on":true,
-            "max_clients":500
+            "max_clients":500,
+            "log_file" : "../../tests/testlog"
         }
     ]
 }
@@ -154,7 +163,9 @@ var configJsonC = `
 // adds 127.0.0.1:4655, a secure server
 var configJsonD = `
 {
-"pid_file" : "./pidfile.pid",
+    "log_file" : "../../tests/testlog",
+    "log_level" : "debug",
+    "pid_file" : "./pidfile.pid",
     "allowed_hosts": [
       "guerrillamail.com",
       "guerrillamailblock.com",
@@ -177,7 +188,8 @@ var configJsonD = `
             "listen_interface":"127.0.0.1:2552",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 1000
+            "max_clients": 1000,
+            "log_file" : "../../tests/testlog"
         },
         {
             "is_enabled" : true,
@@ -189,23 +201,26 @@ var configJsonD = `
             "listen_interface":"127.0.0.1:4655",
             "start_tls_on":false,
             "tls_always_on":true,
-            "max_clients":500
+            "max_clients":500,
+            "log_file" : "../../tests/testlog"
         }
     ]
 }
 `
 
+const testPauseDuration = time.Millisecond * 600
+
 // reload config
 func sigHup() {
 	if data, err := ioutil.ReadFile("pidfile.pid"); err == nil {
-		log.Infof("pid read is %s", data)
+		mainlog.Infof("pid read is %s", data)
 		ecmd := exec.Command("kill", "-HUP", string(data))
 		_, err = ecmd.Output()
 		if err != nil {
-			log.Infof("could not SIGHUP", err)
+			mainlog.Infof("could not SIGHUP", err)
 		}
 	} else {
-		log.WithError(err).Info("sighup - Could not read pidfle")
+		mainlog.WithError(err).Info("sighup - Could not read pidfle")
 	}
 
 }
@@ -213,14 +228,14 @@ func sigHup() {
 // shutdown after calling serve()
 func sigKill() {
 	if data, err := ioutil.ReadFile("pidfile.pid"); err == nil {
-		log.Infof("pid read is %s", data)
+		mainlog.Infof("pid read is %s", data)
 		ecmd := exec.Command("kill", string(data))
 		_, err = ecmd.Output()
 		if err != nil {
-			log.Infof("could not sigkill", err)
+			mainlog.Infof("could not sigkill", err)
 		}
 	} else {
-		log.WithError(err).Info("sigKill - Could not read pidfle")
+		mainlog.WithError(err).Info("sigKill - Could not read pidfle")
 	}
 
 }
@@ -228,18 +243,6 @@ func sigKill() {
 // make sure that we get all the config change events
 func TestCmdConfigChangeEvents(t *testing.T) {
 
-	// hold the output of logs
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	//log.SetOutput(os.Stdout)
-	log.SetOutput(logOut)
-
 	oldconf := &CmdConfig{}
 	oldconf.load([]byte(configJsonA))
 
@@ -254,9 +257,11 @@ func TestCmdConfigChangeEvents(t *testing.T) {
 		"config_change:backend_name":   false,
 		"server_change:new_server":     false,
 	}
+	mainlog, _ = log.GetLogger("off")
+
 	bcfg := backends.BackendConfig{"log_received_mails": true}
-	backend, err := backends.New("dummy", bcfg)
-	app, err := guerrilla.New(&oldconf.AppConfig, backend)
+	backend, err := backends.New("dummy", bcfg, mainlog)
+	app, err := guerrilla.New(&oldconf.AppConfig, backend, mainlog)
 	if err != nil {
 		//log.Info("Failed to create new app", err)
 	}
@@ -299,25 +304,16 @@ func TestCmdConfigChangeEvents(t *testing.T) {
 			break
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	// cleanup
+	os.Truncate("../../tests/testlog", 0)
+
 }
 
-// start server, chnage config, send SIG HUP, confirm that the pidfile changed & backend reloaded
+// start server, change config, send SIG HUP, confirm that the pidfile changed & backend reloaded
 func TestServe(t *testing.T) {
-	// hold the output of logs
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	//log.SetOutput(os.Stdout)
-	log.SetOutput(logOut)
+
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 
 	ioutil.WriteFile("configJsonA.json", []byte(configJsonA), 0644)
 	cmd := &cobra.Command{}
@@ -328,7 +324,7 @@ func TestServe(t *testing.T) {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 
 	data, err := ioutil.ReadFile("pidfile.pid")
 	if err != nil {
@@ -354,7 +350,7 @@ func TestServe(t *testing.T) {
 			t.Error("could not SIGHUP", err)
 			t.FailNow()
 		}
-		time.Sleep(time.Second) // allow sighup to do its job
+		time.Sleep(testPauseDuration) // allow sighup to do its job
 		// did the pidfile change as expected?
 		if _, err := os.Stat("./pidfile2.pid"); os.IsNotExist(err) {
 			t.Error("pidfile not changed after sighup SIGHUP", err)
@@ -364,20 +360,20 @@ func TestServe(t *testing.T) {
 	sigKill()
 	serveWG.Wait()
 
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, err := os.Open("../../tests/testlog")
+	if err != nil {
+		t.Error(err)
+	}
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
-		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "Backend started:dummy"); i < 0 {
 			t.Error("Dummy backend not restared")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
 
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonA.json")
 	os.Remove("./pidfile.pid")
 	os.Remove("./pidfile2.pid")
@@ -389,17 +385,8 @@ func TestServe(t *testing.T) {
 // then SIGHUP (to reload config & trigger config update events),
 // then connect to it & HELO.
 func TestServerAddEvent(t *testing.T) {
-	// hold the output of logs
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonA.json", []byte(configJsonA), 0644)
 	cmd := &cobra.Command{}
@@ -410,7 +397,7 @@ func TestServerAddEvent(t *testing.T) {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration) // allow the server to start
 	// now change the config by adding a server
 	conf := &CmdConfig{}                                 // blank one
 	conf.load([]byte(configJsonA))                       // load configJsonA
@@ -424,7 +411,7 @@ func TestServerAddEvent(t *testing.T) {
 	}
 	// send a sighup signal to the server
 	sigHup()
-	time.Sleep(time.Second * 1) // pause for config to reload
+	time.Sleep(testPauseDuration) // pause for config to reload
 
 	if conn, buffin, err := test.Connect(newServer, 20); err != nil {
 		t.Error("Could not connect to new server", newServer.ListenInterface)
@@ -442,20 +429,18 @@ func TestServerAddEvent(t *testing.T) {
 	// send kill signal and wait for exit
 	sigKill()
 	serveWG.Wait()
-	logOut.Flush()
+
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "New server added [127.0.0.1:2526]"); i < 0 {
 			t.Error("Did not add [127.0.0.1:2526], most likely because Bus.Subscribe(\"server_change:new_server\" didnt fire")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
-
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonA.json")
 	os.Remove("./pidfile.pid")
 
@@ -467,18 +452,8 @@ func TestServerAddEvent(t *testing.T) {
 // then SIGHUP (to reload config & trigger config update events),
 // then connect to 127.0.0.1:2228 & HELO.
 func TestServerStartEvent(t *testing.T) {
-	// hold the output of logs
-
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonA.json", []byte(configJsonA), 0644)
 	cmd := &cobra.Command{}
@@ -489,7 +464,7 @@ func TestServerStartEvent(t *testing.T) {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 	// now change the config by adding a server
 	conf := &CmdConfig{}           // blank one
 	conf.load([]byte(configJsonA)) // load configJsonA
@@ -504,7 +479,7 @@ func TestServerStartEvent(t *testing.T) {
 	}
 	// send a sighup signal to the server
 	sigHup()
-	time.Sleep(time.Second * 1) // pause for config to reload
+	time.Sleep(testPauseDuration) // pause for config to reload
 
 	if conn, buffin, err := test.Connect(newConf.Servers[1], 20); err != nil {
 		t.Error("Could not connect to new server", newConf.Servers[1].ListenInterface)
@@ -521,20 +496,17 @@ func TestServerStartEvent(t *testing.T) {
 	// send kill signal and wait for exit
 	sigKill()
 	serveWG.Wait()
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "Starting server [127.0.0.1:2228]"); i < 0 {
 			t.Error("did not add [127.0.0.1:2228], most likely because Bus.Subscribe(\"server_change:start_server\" didnt fire")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
-
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonA.json")
 	os.Remove("./pidfile.pid")
 
@@ -550,18 +522,8 @@ func TestServerStartEvent(t *testing.T) {
 // then connect to 127.0.0.1:2228 - it should not connect
 
 func TestServerStopEvent(t *testing.T) {
-	// hold the output of logs
-	return
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonA.json", []byte(configJsonA), 0644)
 	cmd := &cobra.Command{}
@@ -572,7 +534,7 @@ func TestServerStopEvent(t *testing.T) {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 	// now change the config by enabling a server
 	conf := &CmdConfig{}           // blank one
 	conf.load([]byte(configJsonA)) // load configJsonA
@@ -587,7 +549,7 @@ func TestServerStopEvent(t *testing.T) {
 	}
 	// send a sighup signal to the server
 	sigHup()
-	time.Sleep(time.Second * 1) // pause for config to reload
+	time.Sleep(testPauseDuration) // pause for config to reload
 
 	if conn, buffin, err := test.Connect(newConf.Servers[1], 20); err != nil {
 		t.Error("Could not connect to new server", newConf.Servers[1].ListenInterface)
@@ -613,7 +575,7 @@ func TestServerStopEvent(t *testing.T) {
 	}
 	// send a sighup signal to the server
 	sigHup()
-	time.Sleep(time.Second * 1) // pause for config to reload
+	time.Sleep(testPauseDuration) // pause for config to reload
 
 	// it should not connect to the server
 	if _, _, err := test.Connect(newConf.Servers[1], 20); err == nil {
@@ -623,20 +585,18 @@ func TestServerStopEvent(t *testing.T) {
 	sigKill()
 	serveWG.Wait()
 
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
-		if i := strings.Index(logOutput, "Server [127.0.0.1:2228] has stopped"); i < 0 {
+		if i := strings.Index(logOutput, "Server [127.0.0.1:2228] stopped"); i < 0 {
 			t.Error("did not stop [127.0.0.1:2228], most likely because Bus.Subscribe(\"server_change:stop_server\" didnt fire")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
 
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonA.json")
 	os.Remove("./pidfile.pid")
 
@@ -650,18 +610,8 @@ func TestServerStopEvent(t *testing.T) {
 // connect to 127.0.0.1:4655 & HELO & try RCPT TO, grr.la should work
 
 func TestAllowedHostsEvent(t *testing.T) {
-	// hold the output of logs
-
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonD.json", []byte(configJsonD), 0644)
 	conf := &CmdConfig{}           // blank one
@@ -669,13 +619,13 @@ func TestAllowedHostsEvent(t *testing.T) {
 	cmd := &cobra.Command{}
 	configPath = "configJsonD.json"
 	var serveWG sync.WaitGroup
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 	serveWG.Add(1)
 	go func() {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 
 	// now connect and try RCPT TO with an invalid host
 	if conn, buffin, err := test.Connect(conf.AppConfig.Servers[1], 20); err != nil {
@@ -708,7 +658,7 @@ func TestAllowedHostsEvent(t *testing.T) {
 	}
 	// send a sighup signal to the server to reload config
 	sigHup()
-	time.Sleep(time.Second) // pause for config to reload
+	time.Sleep(testPauseDuration) // pause for config to reload
 
 	// now repeat the same conversion, RCPT TO should be accepted
 	if conn, buffin, err := test.Connect(conf.AppConfig.Servers[1], 20); err != nil {
@@ -733,20 +683,17 @@ func TestAllowedHostsEvent(t *testing.T) {
 	// send kill signal and wait for exit
 	sigKill()
 	serveWG.Wait()
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "allowed_hosts config changed, a new list was set"); i < 0 {
 			t.Error("did not change allowed_hosts, most likely because Bus.Subscribe(\"config_change:allowed_hosts\" didnt fire")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
-
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonD.json")
 	os.Remove("./pidfile.pid")
 
@@ -759,18 +706,14 @@ func TestAllowedHostsEvent(t *testing.T) {
 // should get a new tls event & able to STARTTLS with no problem
 
 func TestTLSConfigEvent(t *testing.T) {
-	// hold the output of logs
-
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
+	// pause for generated cert to output on slow machines
+	time.Sleep(testPauseDuration)
+	// did cert output?
+	if _, err := os.Stat("../../tests/mail2.guerrillamail.com.cert.pem"); err != nil {
+		t.Error("Did not create cert ", err)
+	}
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonD.json", []byte(configJsonD), 0644)
 	conf := &CmdConfig{}           // blank one
@@ -778,13 +721,12 @@ func TestTLSConfigEvent(t *testing.T) {
 	cmd := &cobra.Command{}
 	configPath = "configJsonD.json"
 	var serveWG sync.WaitGroup
-	time.Sleep(time.Second)
 	serveWG.Add(1)
 	go func() {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 
 	// Test STARTTLS handshake
 	testTlsHandshake := func() {
@@ -809,7 +751,7 @@ func TestTLSConfigEvent(t *testing.T) {
 								t.Error("Failed to handshake", conf.AppConfig.Servers[0].ListenInterface)
 							} else {
 								conn = tlsConn
-								log.Info("TLS Handshake succeeded")
+								mainlog.Info("TLS Handshake succeeded")
 							}
 
 						}
@@ -821,31 +763,43 @@ func TestTLSConfigEvent(t *testing.T) {
 	}
 	testTlsHandshake()
 
+	if err := os.Remove("../../tests/mail2.guerrillamail.com.cert.pem"); err != nil {
+		t.Error("could not remove cert", err)
+	}
+	if err := os.Remove("../../tests/mail2.guerrillamail.com.key.pem"); err != nil {
+		t.Error("could not remove key", err)
+	}
+
 	// generate a new cert
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
+	// pause for generated cert to output
+	time.Sleep(testPauseDuration)
+	// did cert output?
+	if _, err := os.Stat("../../tests/mail2.guerrillamail.com.cert.pem"); err != nil {
+		t.Error("Did not create cert ", err)
+	}
+
 	sigHup()
 
-	time.Sleep(time.Second) // pause for config to reload
+	time.Sleep(testPauseDuration * 2) // pause for config to reload
 	testTlsHandshake()
 
-	time.Sleep(time.Second)
+	//time.Sleep(testPauseDuration)
 	// send kill signal and wait for exit
 	sigKill()
 	serveWG.Wait()
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "Server [127.0.0.1:2552] new TLS configuration loaded"); i < 0 {
 			t.Error("did not change tls, most likely because Bus.Subscribe(\"server_change:tls_config\" didnt fire")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
 
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonD.json")
 	os.Remove("./pidfile.pid")
 
@@ -854,46 +808,34 @@ func TestTLSConfigEvent(t *testing.T) {
 // Test for missing TLS certificate, when starting or config reload
 
 func TestBadTLS(t *testing.T) {
-	// hold the output of logs
-
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
-
-	//testcert.GenerateCert("mail2.guerrillamail.com", "", 365 * 24 * time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	//log.SetLevel(log.DebugLevel) // it will trash std out of debug
-	log.SetLevel(log.InfoLevel)
-	log.SetOutput(logOut)
-	//log.SetOutput(os.Stdout)
+	mainlog, _ = log.GetLogger("../../tests/testlog")
 	if err := os.Remove("./../../tests/mail2.guerrillamail.com.cert.pem"); err != nil {
-		log.WithError(err).Error("could not remove ./../../tests/mail2.guerrillamail.com.cert.pem")
+		mainlog.WithError(err).Error("could not remove ./../../tests/mail2.guerrillamail.com.cert.pem")
 	} else {
-		log.Info("removed ./../../tests/mail2.guerrillamail.com.cert.pem")
+		mainlog.Info("removed ./../../tests/mail2.guerrillamail.com.cert.pem")
 	}
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonD.json", []byte(configJsonD), 0644)
 	conf := &CmdConfig{}           // blank one
 	conf.load([]byte(configJsonD)) // load configJsonD
+	conf.Servers[0].Timeout = 1
 	cmd := &cobra.Command{}
 	configPath = "configJsonD.json"
 	var serveWG sync.WaitGroup
-	time.Sleep(time.Second)
+
 	serveWG.Add(1)
 	go func() {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 
 	// Test STARTTLS handshake
 	testTlsHandshake := func() {
 		if conn, buffin, err := test.Connect(conf.AppConfig.Servers[0], 20); err != nil {
 			t.Error("Could not connect to server", conf.AppConfig.Servers[0].ListenInterface, err)
 		} else {
+			conn.SetDeadline(time.Now().Add(time.Second))
 			if result, err := test.Command(conn, buffin, "HELO"); err == nil {
 				expect := "250 mail.test.com Hello"
 				if strings.Index(result, expect) != 0 {
@@ -909,7 +851,7 @@ func TestBadTLS(t *testing.T) {
 								ServerName:         "127.0.0.1",
 							})
 							if err := tlsConn.Handshake(); err != nil {
-								log.Info("TLS Handshake failed")
+								mainlog.Info("TLS Handshake failed")
 							} else {
 								t.Error("Handshake succeeded, expected it to fail", conf.AppConfig.Servers[0].ListenInterface)
 								conn = tlsConn
@@ -933,27 +875,24 @@ func TestBadTLS(t *testing.T) {
 	//testcert.GenerateCert("mail2.guerrillamail.com", "", 365 * 24 * time.Hour, false, 2048, "P256", "../../tests/")
 	sigHup()
 
-	time.Sleep(time.Second) // pause for config to reload
+	time.Sleep(testPauseDuration) // pause for config to reload
 	testTlsHandshake()
 
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 	// send kill signal and wait for exit
 	sigKill()
 	serveWG.Wait()
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "failed to load the new TLS configuration"); i < 0 {
 			t.Error("did not detect TLS load failure")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
-
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonD.json")
 	os.Remove("./pidfile.pid")
 
@@ -963,20 +902,8 @@ func TestBadTLS(t *testing.T) {
 // Start with configJsonD.json
 
 func TestSetTimeoutEvent(t *testing.T) {
-	// hold the output of logs
-
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
-
+	//mainlog, _ = log.GetLogger("../../tests/testlog")
 	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
-
 	// start the server by emulating the serve command
 	ioutil.WriteFile("configJsonD.json", []byte(configJsonD), 0644)
 	conf := &CmdConfig{}           // blank one
@@ -984,13 +911,13 @@ func TestSetTimeoutEvent(t *testing.T) {
 	cmd := &cobra.Command{}
 	configPath = "configJsonD.json"
 	var serveWG sync.WaitGroup
-	time.Sleep(time.Second)
+
 	serveWG.Add(1)
 	go func() {
 		serve(cmd, []string{})
 		serveWG.Done()
 	}()
-	time.Sleep(time.Second)
+	time.Sleep(testPauseDuration)
 
 	if conn, buffin, err := test.Connect(conf.AppConfig.Servers[0], 20); err != nil {
 		t.Error("Could not connect to server", conf.AppConfig.Servers[0].ListenInterface, err)
@@ -1020,20 +947,99 @@ func TestSetTimeoutEvent(t *testing.T) {
 	// send kill signal and wait for exit
 	sigKill()
 	serveWG.Wait()
-	logOut.Flush()
 	// did backend started as expected?
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "i/o timeout"); i < 0 {
 			t.Error("Connection to 127.0.0.1:2552 didn't timeout as expected")
 		}
 	}
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	// cleanup
+	os.Truncate("../../tests/testlog", 0)
+	os.Remove("configJsonD.json")
+	os.Remove("./pidfile.pid")
+
+}
+
+// Test debug level config change
+// Start in log_level = debug
+// Load config & start server
+func TestDebugLevelChange(t *testing.T) {
+	//mainlog, _ = log.GetLogger("../../tests/testlog")
+	testcert.GenerateCert("mail2.guerrillamail.com", "", 365*24*time.Hour, false, 2048, "P256", "../../tests/")
+	// start the server by emulating the serve command
+	ioutil.WriteFile("configJsonD.json", []byte(configJsonD), 0644)
+	conf := &CmdConfig{}           // blank one
+	conf.load([]byte(configJsonD)) // load configJsonD
+	conf.LogLevel = "debug"
+	cmd := &cobra.Command{}
+	configPath = "configJsonD.json"
+	var serveWG sync.WaitGroup
+
+	serveWG.Add(1)
+	go func() {
+		serve(cmd, []string{})
+		serveWG.Done()
+	}()
+	time.Sleep(testPauseDuration)
+
+	if conn, buffin, err := test.Connect(conf.AppConfig.Servers[0], 20); err != nil {
+		t.Error("Could not connect to server", conf.AppConfig.Servers[0].ListenInterface, err)
+	} else {
+		if result, err := test.Command(conn, buffin, "HELO"); err == nil {
+			expect := "250 mail.test.com Hello"
+			if strings.Index(result, expect) != 0 {
+				t.Error("Expected", expect, "but got", result)
+			}
+		}
+		conn.Close()
+	}
+	// set the log_level to info
 
+	newConf := conf // copy the cmdConfg
+	newConf.LogLevel = "info"
+	if jsonbytes, err := json.Marshal(newConf); err == nil {
+		ioutil.WriteFile("configJsonD.json", []byte(jsonbytes), 0644)
+	} else {
+		t.Error(err)
+	}
+	// send a sighup signal to the server to reload config
+	sigHup()
+	time.Sleep(testPauseDuration) // log to change
+
+	// connect again, this time we should see info
+	if conn, buffin, err := test.Connect(conf.AppConfig.Servers[0], 20); err != nil {
+		t.Error("Could not connect to server", conf.AppConfig.Servers[0].ListenInterface, err)
+	} else {
+		if result, err := test.Command(conn, buffin, "NOOP"); err == nil {
+			expect := "200 2.0.0 OK"
+			if strings.Index(result, expect) != 0 {
+				t.Error("Expected", expect, "but got", result)
+			}
+		}
+		conn.Close()
+	}
+
+	// send kill signal and wait for exit
+	sigKill()
+	serveWG.Wait()
+	// did backend started as expected?
+	fd, _ := os.Open("../../tests/testlog")
+	if read, err := ioutil.ReadAll(fd); err == nil {
+		logOutput := string(read)
+		//fmt.Println(logOutput)
+		if i := strings.Index(logOutput, "log level changed to [info]"); i < 0 {
+			t.Error("Log level did not change to [info]")
+		}
+		// This should not be there:
+		if i := strings.Index(logOutput, "Client sent: NOOP"); i != -1 {
+			t.Error("Log level did not change to [info], we are still seeing debug messages")
+		}
+	}
 	// cleanup
+	os.Truncate("../../tests/testlog", 0)
 	os.Remove("configJsonD.json")
 	os.Remove("./pidfile.pid")
 

cmd/guerrillad/version.go

@@ -1,7 +1,6 @@
 package main
 
 import (
-	log "github.com/Sirupsen/logrus"
 	"github.com/spf13/cobra"
 
 	guerrilla "github.com/flashmob/go-guerrilla"
@@ -21,7 +20,7 @@ func init() {
 }
 
 func logVersion() {
-	log.Infof("guerrillad %s", guerrilla.Version)
-	log.Debugf("Build Time: %s", guerrilla.BuildTime)
-	log.Debugf("Commit:     %s", guerrilla.Commit)
+	mainlog.Infof("guerrillad %s", guerrilla.Version)
+	mainlog.Debugf("Build Time: %s", guerrilla.BuildTime)
+	mainlog.Debugf("Commit:     %s", guerrilla.Commit)
 }

config.go

@@ -14,6 +14,8 @@ type AppConfig struct {
 	Servers      []ServerConfig `json:"servers"`
 	AllowedHosts []string       `json:"allowed_hosts"`
 	PidFile      string         `json:"pid_file"`
+	LogFile      string         `json:"log_file,omitempty"`
+	LogLevel     string         `json:"log_level,omitempty"`
 }
 
 // ServerConfig specifies config options for a single server
@@ -63,6 +65,17 @@ func (c *AppConfig) EmitChangeEvents(oldConfig *AppConfig, app Guerrilla) {
 	if strings.Compare(oldConfig.PidFile, c.PidFile) != 0 {
 		app.Publish("config_change:pid_file", c)
 	}
+	// has mainlog log changed?
+	if strings.Compare(oldConfig.LogFile, c.LogFile) != 0 {
+		app.Publish("config_change:log_file", c)
+	} else {
+		// since config file has not changed, we reload it
+		app.Publish("config_change:reopen_log_file", c)
+	}
+	// has log level changed?
+	if strings.Compare(oldConfig.LogLevel, c.LogLevel) != 0 {
+		app.Publish("config_change:log_level", c)
+	}
 	// server config changes
 	oldServers := oldConfig.getServers()
 	for iface, newServer := range c.getServers() {
@@ -117,10 +130,10 @@ func (sc *ServerConfig) emitChangeEvents(oldServer *ServerConfig, app Guerrilla)
 	}
 	// log file change?
 	if _, ok := changes["LogFile"]; ok {
-		app.Publish("server_change:"+sc.ListenInterface+":new_log_file", sc)
+		app.Publish("server_change:new_log_file", sc)
 	} else {
 		// since config file has not changed, we reload it
-		app.Publish("server_change:"+sc.ListenInterface+":reopen_log_file", sc)
+		app.Publish("server_change:reopen_log_file", sc)
 	}
 	// timeout changed
 	if _, ok := changes["Timeout"]; ok {

config_test.go

@@ -1,10 +1,8 @@
 package guerrilla
 
 import (
-	"bufio"
-	"bytes"
-	log "github.com/Sirupsen/logrus"
 	"github.com/flashmob/go-guerrilla/backends"
+	"github.com/flashmob/go-guerrilla/log"
 	"github.com/flashmob/go-guerrilla/tests/testcert"
 	"io/ioutil"
 	"os"
@@ -22,6 +20,8 @@ func init() {
 //
 var configJsonA = `
 {
+    "log_file" : "./tests/testlog",
+    "log_level" : "debug",
     "pid_file" : "/var/run/go-guerrilla.pid",
     "allowed_hosts": ["spam4.me","grr.la"],
     "backend_name" : "dummy",
@@ -40,8 +40,7 @@ var configJsonA = `
             "listen_interface":"127.0.0.1:2526",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 2,
-            "log_file":"/dev/stdout"
+            "max_clients": 2
         },
 
         {
@@ -54,8 +53,7 @@ var configJsonA = `
             "listen_interface":"127.0.0.1:2527",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients":1,
-            "log_file":"/dev/stdout"
+            "max_clients":1
         },
 
         {
@@ -68,8 +66,7 @@ var configJsonA = `
             "listen_interface":"127.0.0.1:9999",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 2,
-            "log_file":"/dev/stdout"
+            "max_clients": 2
         },
 
         {
@@ -82,8 +79,7 @@ var configJsonA = `
             "listen_interface":"127.0.0.1:3333",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 2,
-            "log_file":"/dev/stdout"
+            "max_clients": 2
         }
 
 
@@ -98,6 +94,8 @@ var configJsonA = `
 
 var configJsonB = `
 {
+    "log_file" : "./tests/testlog",
+    "log_level" : "debug",
     "pid_file" : "/var/run/different-go-guerrilla.pid",
     "allowed_hosts": ["spam4.me","grr.la","newhost.com"],
     "backend_name" : "dummy",
@@ -116,8 +114,7 @@ var configJsonB = `
             "listen_interface":"127.0.0.1:2526",
             "start_tls_on":false,
             "tls_always_on":true,
-            "max_clients": 3,
-            "log_file":"/var/log/smtpd.log"
+            "max_clients": 3
         },
         {
             "is_enabled" : true,
@@ -129,8 +126,7 @@ var configJsonB = `
             "listen_interface":"127.0.0.1:2527",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 2,
-            "log_file":"/dev/stdout"
+            "max_clients": 2
         },
 
         {
@@ -143,8 +139,7 @@ var configJsonB = `
             "listen_interface":"127.0.0.1:4654",
             "start_tls_on":false,
             "tls_always_on":true,
-            "max_clients":1,
-            "log_file":"/dev/stdout"
+            "max_clients":1
         },
 
         {
@@ -157,8 +152,7 @@ var configJsonB = `
             "listen_interface":"127.0.0.1:3333",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 2,
-            "log_file":"/dev/stdout"
+            "max_clients": 2
         }
     ]
 }
@@ -201,39 +195,33 @@ func TestSampleConfig(t *testing.T) {
 // make sure that we get all the config change events
 func TestConfigChangeEvents(t *testing.T) {
 
-	// hold the output of logs
-	var logBuffer bytes.Buffer
-	// logs redirected to this writer
-	var logOut *bufio.Writer
-	// read the logs
-	var logIn *bufio.Reader
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	//log.SetOutput(os.Stdout)
-	log.SetOutput(logOut)
-
 	oldconf := &AppConfig{}
 	oldconf.Load([]byte(configJsonA))
+	logger, _ := log.GetLogger(oldconf.LogFile)
 	bcfg := backends.BackendConfig{"log_received_mails": true}
-	backend, _ := backends.New("dummy", bcfg)
-	app, _ := New(oldconf, backend)
+	backend, _ := backends.New("dummy", bcfg, logger)
+	app, _ := New(oldconf, backend, logger)
 	// simulate timestamp change
 	time.Sleep(time.Second + time.Millisecond*500)
 	os.Chtimes(oldconf.Servers[1].PrivateKeyFile, time.Now(), time.Now())
 	os.Chtimes(oldconf.Servers[1].PublicKeyFile, time.Now(), time.Now())
 	newconf := &AppConfig{}
 	newconf.Load([]byte(configJsonB))
+	newconf.Servers[0].LogFile = "/dev/stderr" // test for log file change
+	newconf.LogLevel = "off"
+	newconf.LogFile = "off"
 	expectedEvents := map[string]bool{
-		"config_change:pid_file":                       false,
-		"config_change:allowed_hosts":                  false,
-		"server_change:new_server":                     false, // 127.0.0.1:4654 will be added
-		"server_change:remove_server":                  false, // 127.0.0.1:9999 server removed
-		"server_change:stop_server":                    false, // 127.0.0.1:3333: server (disabled)
-		"server_change:127.0.0.1:2526:new_log_file":    false,
-		"server_change:127.0.0.1:2527:reopen_log_file": false,
-		"server_change:timeout":                        false, // 127.0.0.1:2526 timeout
-		//"server_change:tls_config":      false, // 127.0.0.1:2526
+		"config_change:pid_file":        false,
+		"config_change:log_file":        false,
+		"config_change:log_level":       false,
+		"config_change:allowed_hosts":   false,
+		"server_change:new_server":      false, // 127.0.0.1:4654 will be added
+		"server_change:remove_server":   false, // 127.0.0.1:9999 server removed
+		"server_change:stop_server":     false, // 127.0.0.1:3333: server (disabled)
+		"server_change:new_log_file":    false, // 127.0.0.1:2526
+		"server_change:reopen_log_file": false, // 127.0.0.1:2527
+		"server_change:timeout":         false, // 127.0.0.1:2526 timeout
+		//"server_change:tls_config":    false, // 127.0.0.1:2526
 		"server_change:max_clients": false, // 127.0.0.1:2526
 		"server_change:tls_config":  false, // 127.0.0.1:2527 timestamp changed on certificates
 	}
@@ -279,6 +267,5 @@ func TestConfigChangeEvents(t *testing.T) {
 	}
 
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate(oldconf.LogFile, 0)
 }

glide.lock

@@ -1,5 +1,5 @@
-hash: 9d5e16555ee2b6363588a60d63b9ba42952cf8a77907b4629aca810f774e3f7b
-updated: 2017-01-06T01:17:48.317018392+11:00
+hash: 1a8fddacae80af03b3cb67287a2a39396a4b38a0c7f805f63325293a19230853
+updated: 2017-02-01T09:34:30.442747666+11:00
 imports:
 - name: github.com/asaskevich/EventBus
   version: ab9e5ceb2cc1ca6f36a5813c928c534e837681c2
@@ -8,6 +8,8 @@ imports:
   subpackages:
   - internal
   - redis
+- name: github.com/go-sql-driver/mysql
+  version: a0583e0143b1624142adab07e0e97fe106d99561
 - name: github.com/inconshreveable/mousetrap
   version: 76626ae9c91c4f2a10f34cad8ce83ea42c93bb75
 - name: github.com/Sirupsen/logrus

glide.yaml

@@ -17,3 +17,5 @@ import:
   version: ~1.1.1
 - package: github.com/asaskevich/EventBus
   version: ab9e5ceb2cc1ca6f36a5813c928c534e837681c2
+- package: github.com/go-sql-driver/mysql
+  version: ^1.3.0

goguerrilla.conf.sample

@@ -1,4 +1,6 @@
 {
+    "log_file" : "stderr",
+    "log_level" : "info",
     "allowed_hosts": [
       "guerrillamail.com",
       "guerrillamailblock.com",
@@ -22,7 +24,8 @@
             "listen_interface":"127.0.0.1:25",
             "start_tls_on":true,
             "tls_always_on":false,
-            "max_clients": 1000
+            "max_clients": 1000,
+            "log_file" : "stderr"
         },
         {
             "is_enabled" : true,
@@ -34,7 +37,8 @@
             "listen_interface":"127.0.0.1:465",
             "start_tls_on":false,
             "tls_always_on":true,
-            "max_clients":500
+            "max_clients":500,
+            "log_file" : "stderr"
         }
     ]
 }

guerrilla.go

@@ -2,10 +2,11 @@ package guerrilla
 
 import (
 	"errors"
-	log "github.com/Sirupsen/logrus"
 	evbus "github.com/asaskevich/EventBus"
 	"github.com/flashmob/go-guerrilla/backends"
+	"github.com/flashmob/go-guerrilla/log"
 	"sync"
+	"sync/atomic"
 )
 
 const (
@@ -38,6 +39,7 @@ type Guerrilla interface {
 	Subscribe(topic string, fn interface{}) error
 	Publish(topic string, args ...interface{})
 	Unsubscribe(topic string, handler interface{}) error
+	SetLogger(log.Logger)
 }
 
 type guerrilla struct {
@@ -45,19 +47,39 @@ type guerrilla struct {
 	servers map[string]*server
 	backend backends.Backend
 	// guard controls access to g.servers
-	guard sync.Mutex
-	state int8
-	bus   *evbus.EventBus
+	guard   sync.Mutex
+	state   int8
+	bus     *evbus.EventBus
+	mainlog logStore
+}
+
+type logStore struct {
+	atomic.Value
+}
+
+// Get loads the log.logger in an atomic operation. Returns a stderr logger if not able to load
+func (ls *logStore) Get() log.Logger {
+	if v, ok := ls.Load().(log.Logger); ok {
+		return v
+	}
+	l, _ := log.GetLogger(log.OutputStderr.String())
+	return l
 }
 
 // Returns a new instance of Guerrilla with the given config, not yet running.
-func New(ac *AppConfig, b backends.Backend) (Guerrilla, error) {
+func New(ac *AppConfig, b backends.Backend, l log.Logger) (Guerrilla, error) {
 	g := &guerrilla{
 		Config:  *ac, // take a local copy
 		servers: make(map[string]*server, len(ac.Servers)),
 		backend: b,
 		bus:     evbus.New(),
 	}
+	g.mainlog.Store(l)
+
+	if ac.LogLevel != "" {
+		g.mainlog.Get().SetLevel(ac.LogLevel)
+	}
+
 	g.state = GuerrillaStateNew
 	err := g.makeServers()
 
@@ -68,16 +90,16 @@ func New(ac *AppConfig, b backends.Backend) (Guerrilla, error) {
 
 // Instantiate servers
 func (g *guerrilla) makeServers() error {
-	log.Debug("making servers")
+	g.mainlog.Get().Debug("making servers")
 	var errs Errors
 	for _, sc := range g.Config.Servers {
 		if _, ok := g.servers[sc.ListenInterface]; ok {
 			// server already instantiated
 			continue
 		}
-		server, err := newServer(&sc, g.backend)
+		server, err := newServer(&sc, g.backend, g.mainlog.Get())
 		if err != nil {
-			log.WithError(err).Errorf("Failed to create server [%s]", sc.ListenInterface)
+			g.mainlog.Get().WithError(err).Errorf("Failed to create server [%s]", sc.ListenInterface)
 			errs = append(errs, err)
 		}
 		if server != nil {
@@ -143,6 +165,7 @@ func (g *guerrilla) mapServers(callback func(*server)) map[string]*server {
 	return g.servers
 }
 
+// subscribeEvents subscribes event handlers for configuration change events
 func (g *guerrilla) subscribeEvents() {
 
 	// allowed_hosts changed, set for all servers
@@ -150,10 +173,41 @@ func (g *guerrilla) subscribeEvents() {
 		g.mapServers(func(server *server) {
 			server.setAllowedHosts(c.AllowedHosts)
 		})
-		log.Infof("allowed_hosts config changed, a new list was set")
+		g.mainlog.Get().Infof("allowed_hosts config changed, a new list was set")
 	})
 
-	// server was removed from config
+	// the main log file changed
+	g.Subscribe("config_change:log_file", func(c *AppConfig) {
+		var err error
+		var l log.Logger
+		if l, err = log.GetLogger(c.LogFile); err == nil {
+			g.mainlog.Store(l)
+			g.mapServers(func(server *server) {
+				server.mainlogStore.Store(l) // it will change to hl on the next accepted client
+			})
+			g.mainlog.Get().Infof("main log for new clients changed to to [%s]", c.LogFile)
+		} else {
+			g.mainlog.Get().WithError(err).Errorf("main logging change failed [%s]", c.LogFile)
+		}
+
+	})
+
+	// re-open the main log file (file not changed)
+	g.Subscribe("config_change:reopen_log_file", func(c *AppConfig) {
+		g.mainlog.Get().Reopen()
+		g.mainlog.Get().Infof("re-opened main log file [%s]", c.LogFile)
+	})
+
+	// when log level changes, apply to mainlog and server logs
+	g.Subscribe("config_change:log_level", func(c *AppConfig) {
+		g.mainlog.Get().SetLevel(c.LogLevel)
+		g.mapServers(func(server *server) {
+			server.log.SetLevel(c.LogLevel)
+		})
+		g.mainlog.Get().Infof("log level changed to [%s]", c.LogLevel)
+	})
+
+	// server config was updated
 	g.Subscribe("server_change:update_config", func(sc *ServerConfig) {
 		if i, _ := g.findServer(sc.ListenInterface); i != -1 {
 			g.setConfig(i, sc)
@@ -165,23 +219,23 @@ func (g *guerrilla) subscribeEvents() {
 		if i, _ := g.findServer(sc.ListenInterface); i == -1 {
 			// not found, lets add it
 			g.addServer(sc)
-			log.Infof("New server added [%s]", sc.ListenInterface)
+			g.mainlog.Get().Infof("New server added [%s]", sc.ListenInterface)
 			if g.state == GuerrillaStateStarted {
 				err := g.Start()
 				if err != nil {
-					log.WithError(err).Info("Event server_change:new_server returned errors when starting")
+					g.mainlog.Get().WithError(err).Info("Event server_change:new_server returned errors when starting")
 				}
 			}
 		}
 	})
-	// start a server that already exists in config and has been instantiated
+	// start a server that already exists in the config and has been instantiated
 	g.Subscribe("server_change:start_server", func(sc *ServerConfig) {
 		if i, server := g.findServer(sc.ListenInterface); i != -1 {
 			if server.state == ServerStateStopped || server.state == ServerStateNew {
-				log.Infof("Starting server [%s]", server.listenInterface)
+				g.mainlog.Get().Infof("Starting server [%s]", server.listenInterface)
 				err := g.Start()
 				if err != nil {
-					log.WithError(err).Info("Event server_change:start_server returned errors when starting")
+					g.mainlog.Get().WithError(err).Info("Event server_change:start_server returned errors when starting")
 				}
 			}
 		}
@@ -191,7 +245,7 @@ func (g *guerrilla) subscribeEvents() {
 		if i, server := g.findServer(sc.ListenInterface); i != -1 {
 			if server.state == ServerStateRunning {
 				server.Shutdown()
-				log.Infof("Server [%s] stopped.", sc.ListenInterface)
+				g.mainlog.Get().Infof("Server [%s] stopped.", sc.ListenInterface)
 			}
 		}
 	})
@@ -200,7 +254,7 @@ func (g *guerrilla) subscribeEvents() {
 		if i, server := g.findServer(sc.ListenInterface); i != -1 {
 			server.Shutdown()
 			g.removeServer(i, sc.ListenInterface)
-			log.Infof("Server [%s] removed from config, stopped it.", sc.ListenInterface)
+			g.mainlog.Get().Infof("Server [%s] removed from config, stopped it.", sc.ListenInterface)
 		}
 	})
 
@@ -208,9 +262,9 @@ func (g *guerrilla) subscribeEvents() {
 	g.Subscribe("server_change:tls_config", func(sc *ServerConfig) {
 		if i, server := g.findServer(sc.ListenInterface); i != -1 {
 			if err := server.configureSSL(); err == nil {
-				log.Infof("Server [%s] new TLS configuration loaded", sc.ListenInterface)
+				g.mainlog.Get().Infof("Server [%s] new TLS configuration loaded", sc.ListenInterface)
 			} else {
-				log.WithError(err).Errorf("Server [%s] failed to load the new TLS configuration", sc.ListenInterface)
+				g.mainlog.Get().WithError(err).Errorf("Server [%s] failed to load the new TLS configuration", sc.ListenInterface)
 			}
 		}
 	})
@@ -226,6 +280,34 @@ func (g *guerrilla) subscribeEvents() {
 			// TODO resize the pool somehow
 		})
 	})
+	// when a server's log file changes
+	g.Subscribe("server_change:new_log_file", func(sc *ServerConfig) {
+		if i, server := g.findServer(sc.ListenInterface); i != -1 {
+			var err error
+			var l log.Logger
+			if l, err = log.GetLogger(sc.LogFile); err == nil {
+				g.mainlog.Store(l)
+				server.logStore.Store(l) // it will change to l on the next accepted client
+				g.mainlog.Get().Infof("Server [%s] changed, new clients will log to: [%s]",
+					sc.ListenInterface,
+					sc.LogFile,
+				)
+			} else {
+				g.mainlog.Get().WithError(err).Errorf(
+					"Server [%s] log change failed to: [%s]",
+					sc.ListenInterface,
+					sc.LogFile,
+				)
+			}
+		}
+	})
+	// when the daemon caught a sighup
+	g.Subscribe("server_change:reopen_log_file", func(sc *ServerConfig) {
+		if i, server := g.findServer(sc.ListenInterface); i != -1 {
+			server.log.Reopen()
+			g.mainlog.Get().Infof("Server [%s] re-opened log file [%s]", sc.ListenInterface, sc.LogFile)
+		}
+	})
 
 }
 
@@ -292,13 +374,13 @@ func (g *guerrilla) Shutdown() {
 	for ListenInterface, s := range g.servers {
 		if s.state == ServerStateRunning {
 			s.Shutdown()
-			log.Infof("shutdown completed for [%s]", ListenInterface)
+			g.mainlog.Get().Infof("shutdown completed for [%s]", ListenInterface)
 		}
 	}
 	if err := g.backend.Shutdown(); err != nil {
-		log.WithError(err).Warn("Backend failed to shutdown")
+		g.mainlog.Get().WithError(err).Warn("Backend failed to shutdown")
 	} else {
-		log.Infof("Backend shutdown completed")
+		g.mainlog.Get().Infof("Backend shutdown completed")
 	}
 }
 
@@ -313,3 +395,7 @@ func (g *guerrilla) Publish(topic string, args ...interface{}) {
 func (g *guerrilla) Unsubscribe(topic string, handler interface{}) error {
 	return g.bus.Unsubscribe(topic, handler)
 }
+
+func (g *guerrilla) SetLogger(l log.Logger) {
+	g.mainlog.Store(l)
+}

log/log.go

@@ -0,0 +1,329 @@
+package log
+
+import (
+	"bufio"
+	log "github.com/Sirupsen/logrus"
+	"io"
+	"io/ioutil"
+	"net"
+	"os"
+	"strings"
+	"sync"
+)
+
+type Logger interface {
+	log.FieldLogger
+	WithConn(conn net.Conn) *log.Entry
+	Reopen() error
+	GetLogDest() string
+	SetLevel(level string)
+	GetLevel() string
+	IsDebug() bool
+	AddHook(h log.Hook)
+}
+
+// Implements the Logger interface
+// It's a logrus logger wrapper that contains an instance of our LoggerHook
+type HookedLogger struct {
+
+	// satisfy the log.FieldLogger interface
+	*log.Logger
+
+	h LoggerHook
+}
+
+type loggerCache map[string]Logger
+
+// loggers store the cached loggers created by NewLogger
+var loggers struct {
+	cache loggerCache
+	// mutex guards the cache
+	sync.Mutex
+}
+
+// GetLogger returns a struct that implements Logger (i.e HookedLogger) with a custom hook.
+// It may be new or already created, (ie. singleton factory pattern)
+// The hook has been initialized with dest
+// dest can can be a path to a file, or the following string values:
+// "off" - disable any log output
+// "stdout" - write to standard output
+// "stderr" - write to standard error
+// If the file doesn't exists, a new file will be created. Otherwise it will be appended
+// Each Logger returned is cached on dest, subsequent call will get the cached logger if dest matches
+// If there was an error, the log will revert to stderr instead of using a custom hook
+
+func GetLogger(dest string) (Logger, error) {
+	loggers.Lock()
+	defer loggers.Unlock()
+	if loggers.cache == nil {
+		loggers.cache = make(loggerCache, 1)
+	} else {
+		if l, ok := loggers.cache[dest]; ok {
+			// return the one we found in the cache
+			return l, nil
+		}
+	}
+	logrus := log.New()
+	// we'll use the hook to output instead
+	logrus.Out = ioutil.Discard
+
+	l := &HookedLogger{}
+	l.Logger = logrus
+
+	// cache it
+	loggers.cache[dest] = l
+
+	// setup the hook
+	if h, err := NewLogrusHook(dest); err != nil {
+		// revert back to stderr
+		logrus.Out = os.Stderr
+		return l, err
+	} else {
+		logrus.Hooks.Add(h)
+		l.h = h
+	}
+
+	return l, nil
+
+}
+
+// AddHook adds a new logrus hook
+func (l *HookedLogger) AddHook(h log.Hook) {
+	log.AddHook(h)
+}
+
+func (l *HookedLogger) IsDebug() bool {
+	return l.GetLevel() == log.DebugLevel.String()
+}
+
+// SetLevel sets a log level, one of the LogLevels
+func (l *HookedLogger) SetLevel(level string) {
+	var logLevel log.Level
+	var err error
+	if logLevel, err = log.ParseLevel(level); err != nil {
+		return
+	}
+	l.Level = logLevel
+	log.SetLevel(logLevel)
+}
+
+// GetLevel gets the current log level
+func (l *HookedLogger) GetLevel() string {
+	return l.Level.String()
+}
+
+// Reopen closes the log file and re-opens it
+func (l *HookedLogger) Reopen() error {
+	return l.h.Reopen()
+}
+
+// Fgetname Gets the file name
+func (l *HookedLogger) GetLogDest() string {
+	return l.h.GetLogDest()
+}
+
+// WithConn extends logrus to be able to log with a net.Conn
+func (l *HookedLogger) WithConn(conn net.Conn) *log.Entry {
+	var addr string = "unknown"
+
+	if conn != nil {
+		addr = conn.RemoteAddr().String()
+	}
+	return l.WithField("addr", addr)
+}
+
+// custom logrus hook
+
+// hookMu ensures all io operations are synced. Always on exported functions
+var hookMu sync.Mutex
+
+// LoggerHook extends the log.Hook interface by adding Reopen() and Rename()
+type LoggerHook interface {
+	log.Hook
+	Reopen() error
+	GetLogDest() string
+}
+type LogrusHook struct {
+	w io.Writer
+	// file descriptor, can be re-opened
+	fd *os.File
+	// filename to the file descriptor
+	fname string
+	// txtFormatter that doesn't use colors
+	plainTxtFormatter *log.TextFormatter
+
+	mu sync.Mutex
+}
+
+// newLogrusHook creates a new hook. dest can be a file name or one of the following strings:
+// "stderr" - log to stderr, lines will be written to os.Stdout
+// "stdout" - log to stdout, lines will be written to os.Stdout
+// "off" - no log, lines will be written to ioutil.Discard
+func NewLogrusHook(dest string) (LoggerHook, error) {
+	hookMu.Lock()
+	defer hookMu.Unlock()
+	hook := LogrusHook{fname: dest}
+	err := hook.setup(dest)
+	return &hook, err
+}
+
+type OutputOption int
+
+const (
+	OutputStderr OutputOption = 1 + iota
+	OutputStdout
+	OutputOff
+	OutputNull
+	OutputFile
+)
+
+var outputOptions = [...]string{
+	"stderr",
+	"stdout",
+	"off",
+	"",
+	"file",
+}
+
+func (o OutputOption) String() string {
+	return outputOptions[o-1]
+}
+
+func parseOutputOption(str string) OutputOption {
+	switch str {
+	case "stderr":
+		return OutputStderr
+	case "stdout":
+		return OutputStdout
+	case "off":
+		return OutputOff
+	case "":
+		return OutputNull
+	}
+	return OutputFile
+}
+
+// Setup sets the hook's writer w and file descriptor fd
+// assumes the hook.fd is closed and nil
+func (hook *LogrusHook) setup(dest string) error {
+
+	out := parseOutputOption(dest)
+	if out == OutputNull || out == OutputStderr {
+		hook.w = os.Stderr
+	} else if out == OutputStdout {
+		hook.w = os.Stdout
+	} else if out == OutputOff {
+		hook.w = ioutil.Discard
+	} else {
+		if _, err := os.Stat(dest); err == nil {
+			// file exists open the file for appending
+			if err := hook.openAppend(dest); err != nil {
+				return err
+			}
+		} else {
+			// create the file
+			if err := hook.openCreate(dest); err != nil {
+				return err
+			}
+		}
+	}
+	// disable colors when writing to file
+	if hook.fd != nil {
+		hook.plainTxtFormatter = &log.TextFormatter{DisableColors: true}
+	}
+	return nil
+}
+
+// openAppend opens the dest file for appending. Default to os.Stderr if it can't open dest
+func (hook *LogrusHook) openAppend(dest string) (err error) {
+	fd, err := os.OpenFile(dest, os.O_APPEND|os.O_WRONLY, 0644)
+	if err != nil {
+		log.WithError(err).Error("Could not open log file for appending")
+		hook.w = os.Stderr
+		hook.fd = nil
+		return
+	}
+	hook.w = bufio.NewWriter(fd)
+	hook.fd = fd
+	return
+}
+
+// openCreate creates a new dest file for appending. Default to os.Stderr if it can't open dest
+func (hook *LogrusHook) openCreate(dest string) (err error) {
+	fd, err := os.OpenFile(dest, os.O_CREATE|os.O_TRUNC|os.O_WRONLY, 0644)
+	if err != nil {
+		log.WithError(err).Error("Could not create log file")
+		hook.w = os.Stderr
+		hook.fd = nil
+		return
+	}
+	hook.w = bufio.NewWriter(fd)
+	hook.fd = fd
+	return
+}
+
+// Fire implements the logrus Hook interface. It disables color text formatting if writing to a file
+func (hook *LogrusHook) Fire(entry *log.Entry) error {
+	hookMu.Lock()
+	defer hookMu.Unlock()
+	if hook.fd != nil {
+		// save the old hook
+		oldhook := entry.Logger.Formatter
+		defer func() {
+			// set the back to the old hook after we're done
+			entry.Logger.Formatter = oldhook
+		}()
+		// use the plain text hook
+		entry.Logger.Formatter = hook.plainTxtFormatter
+	}
+	if line, err := entry.String(); err == nil {
+		r := strings.NewReader(line)
+		if _, err = io.Copy(hook.w, r); err != nil {
+			return err
+		}
+		if wb, ok := hook.w.(*bufio.Writer); ok {
+			if err := wb.Flush(); err != nil {
+				return err
+			}
+			if hook.fd != nil {
+				hook.fd.Sync()
+			}
+		}
+		return err
+	} else {
+		return err
+	}
+}
+
+// GetLogDest returns the destination of the log as a string
+func (hook *LogrusHook) GetLogDest() string {
+	hookMu.Lock()
+	defer hookMu.Unlock()
+	return hook.fname
+}
+
+// Levels implements the logrus Hook interface
+func (hook *LogrusHook) Levels() []log.Level {
+	return log.AllLevels
+}
+
+// Reopen closes and re-open log file descriptor, which is a special feature of this hook
+func (hook *LogrusHook) Reopen() error {
+	hookMu.Lock()
+	defer hookMu.Unlock()
+	var err error
+	if hook.fd != nil {
+		if err = hook.fd.Close(); err != nil {
+			return err
+		}
+		// The file could have been re-named by an external program such as logrotate(8)
+		if _, err := os.Stat(hook.fname); err != nil {
+			// The file doesn't exist,create a new one.
+			return hook.openCreate(hook.fname)
+		} else {
+			return hook.openAppend(hook.fname)
+		}
+	}
+	return err
+
+}

pool.go

@@ -2,6 +2,7 @@ package guerrilla
 
 import (
 	"errors"
+	"github.com/flashmob/go-guerrilla/log"
 	"net"
 	"sync"
 	"sync/atomic"
@@ -120,7 +121,7 @@ func (p *Pool) GetActiveClientsCount() int {
 }
 
 // Borrow a Client from the pool. Will block if len(activeClients) > maxClients
-func (p *Pool) Borrow(conn net.Conn, clientID uint64) (Poolable, error) {
+func (p *Pool) Borrow(conn net.Conn, clientID uint64, logger log.Logger) (Poolable, error) {
 	p.poolGuard.Lock()
 	defer p.poolGuard.Unlock()
 
@@ -135,7 +136,7 @@ func (p *Pool) Borrow(conn net.Conn, clientID uint64) (Poolable, error) {
 		case c = <-p.pool:
 			c.init(conn, clientID)
 		default:
-			c = NewClient(conn, clientID)
+			c = NewClient(conn, clientID, logger)
 		}
 		p.activeClientsAdd(c)
 

response/enhanced.go

@@ -2,7 +2,6 @@ package response
 
 import (
 	"fmt"
-	"strconv"
 )
 
 const (
@@ -23,82 +22,323 @@ const (
 	ClassPermanentFailure = 5
 )
 
+// class is a type for ClassSuccess, ClassTransientFailure and ClassPermanentFailure constants
+type class int
+
+// String implements stringer for the class type
+func (c class) String() string {
+	return fmt.Sprintf("%c00", c)
+}
+
 // codeMap for mapping Enhanced Status Code to Basic Code
 // Mapping according to https://www.iana.org/assignments/smtp-enhanced-status-codes/smtp-enhanced-status-codes.xml
-// This might not be entierly useful
+// This might not be entirely useful
 var codeMap = struct {
-	m map[string]int
-}{m: map[string]int{
-	"2.1.0":  250,
-	"2.1.5":  250,
-	"2.3.0":  250,
-	"2.5.0":  250,
-	"2.6.4":  250,
-	"2.6.8":  252,
-	"2.7.0":  220,
-	"4.1.1":  451,
-	"4.1.8":  451,
-	"4.2.4":  450,
-	"4.3.0":  421,
-	"4.3.1":  452,
-	"4.3.2":  453,
-	"4.4.1":  451,
-	"4.4.2":  421,
-	"4.4.3":  451,
-	"4.4.5":  451,
-	"4.5.0":  451,
-	"4.5.1":  430,
-	"4.5.3":  452,
-	"4.5.4":  451,
-	"4.7.0":  450,
-	"4.7.1":  451,
-	"4.7.12": 422,
-	"4.7.15": 450,
-	"4.7.24": 451,
-	"5.1.1":  550,
-	"5.1.3":  501,
-	"5.1.8":  501,
-	"5.1.10": 556,
-	"5.2.2":  552,
-	"5.2.3":  552,
-	"5.3.0":  550,
-	"5.3.4":  552,
-	"5.4.3":  550,
-	"5.5.0":  501,
-	"5.5.1":  500,
-	"5.5.2":  500,
-	"5.5.4":  501,
-	"5.5.6":  500,
-	"5.6.3":  554,
-	"5.6.6":  554,
-	"5.6.7":  553,
-	"5.6.8":  550,
-	"5.6.9":  550,
-	"5.7.0":  550,
-	"5.7.1":  551,
-	"5.7.2":  550,
-	"5.7.4":  504,
-	"5.7.8":  554,
-	"5.7.9":  534,
-	"5.7.10": 523,
-	"5.7.11": 524,
-	"5.7.13": 525,
-	"5.7.14": 535,
-	"5.7.15": 550,
-	"5.7.16": 552,
-	"5.7.17": 500,
-	"5.7.18": 500,
-	"5.7.19": 500,
-	"5.7.20": 550,
-	"5.7.21": 550,
-	"5.7.22": 550,
-	"5.7.23": 550,
-	"5.7.24": 550,
-	"5.7.25": 550,
-	"5.7.26": 550,
-	"5.7.27": 550,
+	m map[EnhancedStatusCode]int
+}{m: map[EnhancedStatusCode]int{
+
+	EnhancedStatusCode{ClassSuccess, OtherAddressStatus}:               250,
+	EnhancedStatusCode{ClassSuccess, DestinationMailboxAddressValid}:   250,
+	EnhancedStatusCode{ClassSuccess, OtherOrUndefinedMailSystemStatus}: 250,
+	EnhancedStatusCode{ClassSuccess, OtherOrUndefinedProtocolStatus}:   250,
+	EnhancedStatusCode{ClassSuccess, ConversionWithLossPerformed}:      250,
+	EnhancedStatusCode{ClassSuccess, ".6.8"}:                           252,
+	EnhancedStatusCode{ClassSuccess, ".7.0"}:                           220,
+
+	EnhancedStatusCode{ClassTransientFailure, BadDestinationMailboxAddress}:      451,
+	EnhancedStatusCode{ClassTransientFailure, BadSendersSystemAddress}:           451,
+	EnhancedStatusCode{ClassTransientFailure, MailingListExpansionProblem}:       450,
+	EnhancedStatusCode{ClassTransientFailure, OtherOrUndefinedMailSystemStatus}:  421,
+	EnhancedStatusCode{ClassTransientFailure, MailSystemFull}:                    452,
+	EnhancedStatusCode{ClassTransientFailure, SystemNotAcceptingNetworkMessages}: 453,
+	EnhancedStatusCode{ClassTransientFailure, NoAnswerFromHost}:                  451,
+	EnhancedStatusCode{ClassTransientFailure, BadConnection}:                     421,
+	EnhancedStatusCode{ClassTransientFailure, RoutingServerFailure}:              451,
+	EnhancedStatusCode{ClassTransientFailure, NetworkCongestion}:                 451,
+	EnhancedStatusCode{ClassTransientFailure, OtherOrUndefinedProtocolStatus}:    451,
+	EnhancedStatusCode{ClassTransientFailure, InvalidCommand}:                    430,
+	EnhancedStatusCode{ClassTransientFailure, TooManyRecipients}:                 452,
+	EnhancedStatusCode{ClassTransientFailure, InvalidCommandArguments}:           451,
+	EnhancedStatusCode{ClassTransientFailure, ".7.0"}:                            450,
+	EnhancedStatusCode{ClassTransientFailure, ".7.1"}:                            451,
+	EnhancedStatusCode{ClassTransientFailure, ".7.12"}:                           422,
+	EnhancedStatusCode{ClassTransientFailure, ".7.15"}:                           450,
+	EnhancedStatusCode{ClassTransientFailure, ".7.24"}:                           451,
+
+	EnhancedStatusCode{ClassPermanentFailure, BadDestinationMailboxAddress}:            550,
+	EnhancedStatusCode{ClassPermanentFailure, BadDestinationMailboxAddressSyntax}:      501,
+	EnhancedStatusCode{ClassPermanentFailure, BadSendersSystemAddress}:                 501,
+	EnhancedStatusCode{ClassPermanentFailure, ".1.10"}:                                 556,
+	EnhancedStatusCode{ClassPermanentFailure, MailboxFull}:                             552,
+	EnhancedStatusCode{ClassPermanentFailure, MessageLengthExceedsAdministrativeLimit}: 552,
+	EnhancedStatusCode{ClassPermanentFailure, OtherOrUndefinedMailSystemStatus}:        550,
+	EnhancedStatusCode{ClassPermanentFailure, MessageTooBigForSystem}:                  552,
+	EnhancedStatusCode{ClassPermanentFailure, RoutingServerFailure}:                    550,
+	EnhancedStatusCode{ClassPermanentFailure, OtherOrUndefinedProtocolStatus}:          501,
+	EnhancedStatusCode{ClassPermanentFailure, InvalidCommand}:                          500,
+	EnhancedStatusCode{ClassPermanentFailure, SyntaxError}:                             500,
+	EnhancedStatusCode{ClassPermanentFailure, InvalidCommandArguments}:                 501,
+	EnhancedStatusCode{ClassPermanentFailure, ".5.6"}:                                  500,
+	EnhancedStatusCode{ClassPermanentFailure, ConversionRequiredButNotSupported}:       554,
+	EnhancedStatusCode{ClassPermanentFailure, ".6.6"}:                                  554,
+	EnhancedStatusCode{ClassPermanentFailure, ".6.7"}:                                  553,
+	EnhancedStatusCode{ClassPermanentFailure, ".6.8"}:                                  550,
+	EnhancedStatusCode{ClassPermanentFailure, ".6.9"}:                                  550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.0"}:                                  550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.1"}:                                  551,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.2"}:                                  550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.4"}:                                  504,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.8"}:                                  554,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.9"}:                                  534,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.10"}:                                 523,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.11"}:                                 524,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.13"}:                                 525,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.14"}:                                 535,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.15"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.16"}:                                 552,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.17"}:                                 500,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.18"}:                                 500,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.19"}:                                 500,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.20"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.21"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.22"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.23"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.24"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.25"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.26"}:                                 550,
+	EnhancedStatusCode{ClassPermanentFailure, ".7.27"}:                                 550,
 }}
 
+var (
+	// Canned is to be read-only, except in the init() function
+	Canned Responses
+)
+
+// Responses has some already pre-constructed responses
+type Responses struct {
+
+	// The 500's
+	FailLineTooLong              string
+	FailNestedMailCmd            string
+	FailNoSenderDataCmd          string
+	FailNoRecipientsDataCmd      string
+	FailUnrecognizedCmd          string
+	FailMaxUnrecognizedCmd       string
+	FailReadLimitExceededDataCmd string
+	FailMessageSizeExceeded      string
+	FailReadErrorDataCmd         string
+	FailPathTooLong              string
+	FailInvalidAddress           string
+	FailLocalPartTooLong         string
+	FailDomainTooLong            string
+	FailBackendNotRunning        string
+	FailBackendTransaction       string
+	FailBackendTimeout           string
+
+	// The 400's
+	ErrorTooManyRecipients string
+	ErrorRelayDenied       string
+	ErrorShutdown          string
+
+	// The 200's
+	SuccessMailCmd       string
+	SuccessRcptCmd       string
+	SuccessResetCmd      string
+	SuccessVerifyCmd     string
+	SuccessNoopCmd       string
+	SuccessQuitCmd       string
+	SuccessDataCmd       string
+	SuccessStartTLSCmd   string
+	SuccessMessageQueued string
+}
+
+// Called automatically during package load to build up the Responses struct
+func init() {
+
+	// There's even a Wikipedia page for canned responses: https://en.wikipedia.org/wiki/Canned_response
+	Canned = Responses{}
+
+	Canned.FailLineTooLong = (&Response{
+		EnhancedCode: InvalidCommand,
+		BasicCode:    554,
+		Class:        ClassPermanentFailure,
+		Comment:      "Line too long.",
+	}).String()
+
+	Canned.FailNestedMailCmd = (&Response{
+		EnhancedCode: InvalidCommand,
+		BasicCode:    503,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: nested MAIL command",
+	}).String()
+
+	Canned.SuccessMailCmd = (&Response{
+		EnhancedCode: OtherAddressStatus,
+		Class:        ClassSuccess,
+	}).String()
+
+	Canned.SuccessRcptCmd = (&Response{
+		EnhancedCode: DestinationMailboxAddressValid,
+		Class:        ClassSuccess,
+	}).String()
+
+	Canned.SuccessResetCmd = Canned.SuccessMailCmd
+	Canned.SuccessNoopCmd = (&Response{
+		EnhancedCode: OtherStatus,
+		Class:        ClassSuccess,
+	}).String()
+
+	Canned.SuccessVerifyCmd = (&Response{
+		EnhancedCode: OtherOrUndefinedProtocolStatus,
+		BasicCode:    252,
+		Class:        ClassSuccess,
+		Comment:      "Cannot verify user",
+	}).String()
+
+	Canned.ErrorTooManyRecipients = (&Response{
+		EnhancedCode: TooManyRecipients,
+		BasicCode:    452,
+		Class:        ClassTransientFailure,
+		Comment:      "Too many recipients",
+	}).String()
+
+	Canned.ErrorRelayDenied = (&Response{
+		EnhancedCode: BadDestinationMailboxAddress,
+		BasicCode:    454,
+		Class:        ClassTransientFailure,
+		Comment:      "Error: Relay access denied: ",
+	}).String()
+
+	Canned.SuccessQuitCmd = (&Response{
+		EnhancedCode: OtherStatus,
+		BasicCode:    221,
+		Class:        ClassSuccess,
+		Comment:      "Bye",
+	}).String()
+
+	Canned.FailNoSenderDataCmd = (&Response{
+		EnhancedCode: InvalidCommand,
+		BasicCode:    503,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: No sender",
+	}).String()
+
+	Canned.FailNoRecipientsDataCmd = (&Response{
+		EnhancedCode: InvalidCommand,
+		BasicCode:    503,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: No recipients",
+	}).String()
+
+	Canned.SuccessDataCmd = "354 Enter message, ending with '.' on a line by itself"
+
+	Canned.SuccessStartTLSCmd = (&Response{
+		EnhancedCode: OtherStatus,
+		BasicCode:    220,
+		Class:        ClassSuccess,
+		Comment:      "Ready to start TLS",
+	}).String()
+
+	Canned.FailUnrecognizedCmd = (&Response{
+		EnhancedCode: InvalidCommand,
+		BasicCode:    554,
+		Class:        ClassPermanentFailure,
+		Comment:      "Unrecognized command",
+	}).String()
+
+	Canned.FailMaxUnrecognizedCmd = (&Response{
+		EnhancedCode: InvalidCommand,
+		BasicCode:    554,
+		Class:        ClassPermanentFailure,
+		Comment:      "Too many unrecognized commands",
+	}).String()
+
+	Canned.ErrorShutdown = (&Response{
+		EnhancedCode: OtherOrUndefinedMailSystemStatus,
+		BasicCode:    421,
+		Class:        ClassTransientFailure,
+		Comment:      "Server is shutting down. Please try again later. Sayonara!",
+	}).String()
+
+	Canned.FailReadLimitExceededDataCmd = (&Response{
+		EnhancedCode: SyntaxError,
+		BasicCode:    550,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: ",
+	}).String()
+
+	Canned.FailMessageSizeExceeded = (&Response{
+		EnhancedCode: SyntaxError,
+		BasicCode:    550,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: ",
+	}).String()
+
+	Canned.FailReadErrorDataCmd = (&Response{
+		EnhancedCode: OtherOrUndefinedMailSystemStatus,
+		BasicCode:    451,
+		Class:        ClassTransientFailure,
+		Comment:      "Error: ",
+	}).String()
+
+	Canned.FailPathTooLong = (&Response{
+		EnhancedCode: InvalidCommandArguments,
+		BasicCode:    550,
+		Class:        ClassPermanentFailure,
+		Comment:      "Path too long",
+	}).String()
+
+	Canned.FailInvalidAddress = (&Response{
+		EnhancedCode: InvalidCommandArguments,
+		BasicCode:    501,
+		Class:        ClassPermanentFailure,
+		Comment:      "Invalid address",
+	}).String()
+
+	Canned.FailLocalPartTooLong = (&Response{
+		EnhancedCode: InvalidCommandArguments,
+		BasicCode:    550,
+		Class:        ClassPermanentFailure,
+		Comment:      "Local part too long, cannot exceed 64 characters",
+	}).String()
+
+	Canned.FailDomainTooLong = (&Response{
+		EnhancedCode: InvalidCommandArguments,
+		BasicCode:    550,
+		Class:        ClassPermanentFailure,
+		Comment:      "Domain cannot exceed 255 characters",
+	}).String()
+
+	Canned.FailBackendNotRunning = (&Response{
+		EnhancedCode: OtherOrUndefinedProtocolStatus,
+		BasicCode:    554,
+		Class:        ClassPermanentFailure,
+		Comment:      "Transaction failed - backend not running ",
+	}).String()
+
+	Canned.FailBackendTransaction = (&Response{
+		EnhancedCode: OtherOrUndefinedProtocolStatus,
+		BasicCode:    554,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: ",
+	}).String()
+
+	Canned.SuccessMessageQueued = (&Response{
+		EnhancedCode: OtherStatus,
+		BasicCode:    250,
+		Class:        ClassSuccess,
+		Comment:      "OK : queued as ",
+	}).String()
+
+	Canned.FailBackendTimeout = (&Response{
+		EnhancedCode: OtherOrUndefinedProtocolStatus,
+		BasicCode:    554,
+		Class:        ClassPermanentFailure,
+		Comment:      "Error: transaction timeout",
+	}).String()
+
+}
+
 // DefaultMap contains defined default codes (RfC 3463)
 const (
 	OtherStatus                             = ".0.0"
@@ -143,36 +383,49 @@ const (
 	ConversionFailed                        = ".6.5"
 )
 
-// TODO: More defaults needed....
 var defaultTexts = struct {
-	m map[string]string
-}{m: map[string]string{
-	"2.0.0": "OK",
-	"2.1.0": "OK",
-	"2.1.5": "Recipient valid",
-	"2.5.0": "OK",
-	"4.5.3": "Too many recipients",
-	"4.5.4": "Relay access denied",
-	"5.5.1": "Invalid command",
+	m map[EnhancedStatusCode]string
+}{m: map[EnhancedStatusCode]string{
+	EnhancedStatusCode{ClassSuccess, ".0.0"}:          "OK",
+	EnhancedStatusCode{ClassSuccess, ".1.0"}:          "OK",
+	EnhancedStatusCode{ClassSuccess, ".1.5"}:          "OK",
+	EnhancedStatusCode{ClassSuccess, ".5.0"}:          "OK",
+	EnhancedStatusCode{ClassTransientFailure, ".5.3"}: "Too many recipients",
+	EnhancedStatusCode{ClassTransientFailure, ".5.4"}: "Relay access denied",
+	EnhancedStatusCode{ClassPermanentFailure, ".5.1"}: "Invalid command",
 }}
 
 // Response type for Stringer interface
 type Response struct {
-	EnhancedCode string
+	EnhancedCode subjectDetail
 	BasicCode    int
-	Class        int
+	Class        class
 	// Comment is optional
 	Comment string
 }
 
-// Custom returns a custom Response Stringer
+// it looks like this ".5.4"
+type subjectDetail string
+
+// EnhancedStatus are the ones that look like 2.1.0
+type EnhancedStatusCode struct {
+	Class             class
+	SubjectDetailCode subjectDetail
+}
+
+// String returns a string representation of EnhancedStatus
+func (e EnhancedStatusCode) String() string {
+	return fmt.Sprintf("%d%s", e.Class, e.SubjectDetailCode)
+}
+
+// String returns a custom Response as a string
 func (r *Response) String() string {
-	e := buildEnhancedResponseFromDefaultStatus(r.Class, r.EnhancedCode)
+
 	basicCode := r.BasicCode
 	comment := r.Comment
 	if len(comment) == 0 && r.BasicCode == 0 {
-		comment = defaultTexts.m[r.EnhancedCode]
-		if len(comment) == 0 {
+		var ok bool
+		if comment, ok = defaultTexts.m[EnhancedStatusCode{r.Class, r.EnhancedCode}]; !ok {
 			switch r.Class {
 			case 2:
 				comment = "OK"
@@ -183,49 +436,19 @@ func (r *Response) String() string {
 			}
 		}
 	}
+	e := EnhancedStatusCode{r.Class, r.EnhancedCode}
 	if r.BasicCode == 0 {
 		basicCode = getBasicStatusCode(e)
 	}
 
-	return fmt.Sprintf("%d %s %s", basicCode, e, comment)
+	return fmt.Sprintf("%d %s %s", basicCode, e.String(), comment)
 }
 
-/*
-// CustomString builds an enhanced status code string using your custom string and basic code
-func CustomString(enhancedCode string, basicCode, class int, comment string) string {
-	e := buildEnhancedResponseFromDefaultStatus(class, enhancedCode)
-	return fmt.Sprintf("%d %s %s", basicCode, e, comment)
-}
-
-// String builds an enhanced status code string
-func String(enhancedCode string, class int) string {
-	e := buildEnhancedResponseFromDefaultStatus(class, enhancedCode)
-	basicCode := getBasicStatusCode(e)
-	comment := defaultTexts.m[enhancedCode]
-
-	if len(comment) == 0 {
-		switch class {
-		case 2:
-			comment = "OK"
-		case 4:
-			comment = "Temporary failure."
-		case 5:
-			comment = "Permanent failure."
-		}
-	}
-	return CustomString(enhancedCode, basicCode, class, comment)
-}
-*/
-func getBasicStatusCode(enhancedStatusCode string) int {
-	if val, ok := codeMap.m[enhancedStatusCode]; ok {
+// getBasicStatusCode gets the basic status code from codeMap, or fallback code if not mapped
+func getBasicStatusCode(e EnhancedStatusCode) int {
+	if val, ok := codeMap.m[e]; ok {
 		return val
 	}
 	// Fallback if code is not defined
-	fb, _ := strconv.Atoi(fmt.Sprintf("%c00", enhancedStatusCode[0]))
-	return fb
-}
-
-func buildEnhancedResponseFromDefaultStatus(c int, status string) string {
-	// Construct code
-	return fmt.Sprintf("%d%s", c, status)
+	return int(e.Class) * 100
 }

response/enhanced_test.go

@@ -18,13 +18,13 @@ func TestClass(t *testing.T) {
 
 func TestGetBasicStatusCode(t *testing.T) {
 	// Known status code
-	a := getBasicStatusCode("2.5.0")
+	a := getBasicStatusCode(EnhancedStatusCode{2, OtherOrUndefinedProtocolStatus})
 	if a != 250 {
 		t.Errorf("getBasicStatusCode. Int \"%d\" not expected.", a)
 	}
 
 	// Unknown status code
-	b := getBasicStatusCode("2.0.0")
+	b := getBasicStatusCode(EnhancedStatusCode{2, OtherStatus})
 	if b != 200 {
 		t.Errorf("getBasicStatusCode. Int \"%d\" not expected.", b)
 	}
@@ -55,7 +55,8 @@ func TestCustomString(t *testing.T) {
 }
 
 func TestBuildEnhancedResponseFromDefaultStatus(t *testing.T) {
-	a := buildEnhancedResponseFromDefaultStatus(ClassPermanentFailure, InvalidCommand)
+	//a := buildEnhancedResponseFromDefaultStatus(ClassPermanentFailure, InvalidCommand)
+	a := EnhancedStatusCode{ClassPermanentFailure, InvalidCommand}.String()
 	if a != "5.5.1" {
 		t.Errorf("buildEnhancedResponseFromDefaultStatus failed. String \"%s\" not expected.", a)
 	}

response/quote.go

@@ -6,6 +6,10 @@ import (
 	"time"
 )
 
+// This is an easter egg
+
+const CRLF = "\r\n"
+
 var quotes = struct {
 	m map[int]string
 }{m: map[int]string{
@@ -14,139 +18,139 @@ var quotes = struct {
 	2: "214 Walter Sobchak: The chinaman is not the issue here... also dude, Asian American please",
 	3: "214 The Dude: Walter, the chinamen who peed on my rug I can't give him a bill, so what the f**k are you talking about?",
 	4: "214 The Dude: Hey, I know that guy, he's a nihilist. Karl Hungus.",
-	5: `214-Malibu Police Chief: Mr. Treehorn tells us that he had to eject you from his garden party; that you were drunk and abusive.
-214 The Dude: Mr. Treehorn treats objects like women, man.`,
+	5: "214-Malibu Police Chief: Mr. Treehorn tells us that he had to eject you from his garden party; that you were drunk and abusive." + CRLF +
+		"214 The Dude: Mr. Treehorn treats objects like women, man.",
 	6: "214 Walter Sobchak: Shut the f**k up, Donny!",
-	7: `214-Donny: Shut the f**k up, Donny!
-214 Walter Sobchak: Shut the f**k up, Donny!`,
+	7: "214-Donny: Shut the f**k up, Donny!" + CRLF +
+		"214 Walter Sobchak: Shut the f**k up, Donny!",
 	8:  "214 The Dude: It really tied the room together.",
 	9:  "214 Walter Sobchak: Is this your homework, Larry?",
 	10: "214 The Dude: Who the f**k are the Knutsens?",
 	11: "214 The Dude: Yeah,well, that's just, like, your opinion, man.",
-	12: `214-Walter Sobchak: Am I the only one who gives a s**t about the rules?!
-214 Walter Sobchak: Am I the only one who gives a s**t about the rules?`,
-	13: `214-Walter Sobchak: Am I wrong?
-214-The Dude: No, you're not wrong Walter, you're just an ass-hole.
-214 Walter Sobchak: Okay then.`,
-	14: `214-Private Snoop: you see what happens lebowski?
-214-The Dude: nobody calls me lebowski, you got the wrong guy, I'm the the dude, man.
-214-Private Snoop: Your name's Lebowski, Lebowski. Your wife is Bunny.
-214-The Dude: My wife? Bunny? Do you see a wedding ring on my finger? 
-214 Does this place look like I'm f**kin married? The toilet seat's up man!`,
-	15: `214-The Dude: Yeah man. it really tied the room together.
-214-Donny: What tied the room together dude?
-214-The Dude: My rug.
-214-Walter Sobchak: Were you listening to the Dude's story, Donny?
-214-Donny: I was bowling.
-214-Walter Sobchak: So then you have no frame of reference here, Donny, 
-214 You're like a child who wonders in the middle of movie.`,
-	16: `214-The Dude: She probably kidnapped herself.
-214-Donny: What do you mean dude?
-214-The Dude: Rug Peers did not do this. look at it. 
-214-A young trophy wife, marries this guy for his money, she figures he 
-214-hasn't given her enough, she owes money all over town.
-214 Walter Sobchak: That f**kin bitch.`,
-	17: `214 Walter Sobchak: Forget it, Donny, you're out of your element!`,
-	18: `214-Walter Sobchak: You want a toe? I can get you a toe, believe me. 
-214-There are ways, Dude. You don't wanna know about it, believe me.
-214-The Dude: Yeah, but Walter.
-214 Walter Sobchak: Hell, I can get you a toe by 3 o'clock this afternoon with nail polish.`,
+	12: "214-Walter Sobchak: Am I the only one who gives a s**t about the rules?!" + CRLF +
+		"214 Walter Sobchak: Am I the only one who gives a s**t about the rules?",
+	13: "214-Walter Sobchak: Am I wrong?" + CRLF +
+		"214-The Dude: No, you're not wrong Walter, you're just an ass-hole." +
+		"214 Walter Sobchak: Okay then.",
+	14: "214-Private Snoop: you see what happens lebowski?" + CRLF +
+		"214-The Dude: nobody calls me lebowski, you got the wrong guy, I'm the the dude, man." + CRLF +
+		"214-Private Snoop: Your name's Lebowski, Lebowski. Your wife is Bunny." + CRLF +
+		"214-The Dude: My wife? Bunny? Do you see a wedding ring on my finger? " + CRLF +
+		"214 Does this place look like I'm f**kin married? The toilet seat's up man!",
+	15: "214-The Dude: Yeah man. it really tied the room together." + CRLF +
+		"214-Donny: What tied the room together dude?" + CRLF +
+		"214-The Dude: My rug." + CRLF +
+		"214-Walter Sobchak: Were you listening to the Dude's story, Donny?" + CRLF +
+		"214-Donny: I was bowling." + CRLF +
+		"214-Walter Sobchak: So then you have no frame of reference here, Donny, " + CRLF +
+		"214 You're like a child who wonders in the middle of movie.",
+	16: "214-The Dude: She probably kidnapped herself." + CRLF +
+		"214-Donny: What do you mean dude?" + CRLF +
+		"214-The Dude: Rug Peers did not do this. look at it. " + CRLF +
+		"214-A young trophy wife, marries this guy for his money, she figures he " + CRLF +
+		"214-hasn't given her enough, she owes money all over town." + CRLF +
+		"214 Walter Sobchak: That f**kin bitch.",
+	17: "214 Walter Sobchak: Forget it, Donny, you're out of your element!",
+	18: "214-Walter Sobchak: You want a toe? I can get you a toe, believe me." + CRLF +
+		"214-There are ways, Dude. You don't wanna know about it, believe me. " + CRLF +
+		"214-The Dude: Yeah, but Walter." +
+		"214 Walter Sobchak: Hell, I can get you a toe by 3 o'clock this afternoon with nail polish.",
 	19: "214 Walter Sobchak: Calmer then you are.",
 	20: "214 Walter Sobchak: You are entering a world of pain",
 	21: "214 The Dude: This aggression will not stand man.",
 	22: "214 The Dude: His dudeness, duder, or el dudorino",
 	23: "214 Walter Sobchak: Has the whole world gone crazy!",
 	24: "214 Walter Sobchak: Calm down your being very undude.",
-	25: `214-Donny: Are these the Nazis, Walter?
-214 Walter Sobchak: No Donny, these men are nihilists. There's nothing to be afraid of.`,
+	25: "214-Donny: Are these the Nazis, Walter?" + CRLF +
+		"214 Walter Sobchak: No Donny, these men are nihilists. There's nothing to be afraid of.",
 	26: "214 Walter Sobchak: Well, it was parked in the handicapped zone. Perhaps they towed it.",
-	27: `214-Private Snoop: I'm a brother shamus!
-214 The Dude: Brother Seamus? Like an Irish monk?`,
+	27: "214-Private Snoop: I'm a brother shamus!" + CRLF +
+		"214 The Dude: Brother Seamus? Like an Irish monk?",
 	28: "214 Walter Sobchak: Have you ever of Vietnam? You're about to enter a world of pain!",
-	29: `214-Donny: What's a pederast, Walter?
-214 Walter Sobchak: Shut the f**k up, Donny.`,
+	29: "214-Donny: What's a pederast, Walter?" + CRLF +
+		"214 Walter Sobchak: Shut the f**k up, Donny.",
 	30: "214 The Dude: Hey, careful, man, there's a beverage here!",
 	31: "214 The Stranger: Sometimes you eat the bar and sometimes, well, the bar eats you.",
 	32: "214 Walter Sobchak: Goodnight, sweet prince.",
 	33: "214 Jackie Treehorn: People forget the brain is the biggest erogenous zone.",
-	34: `214-The Big Lebowski: What makes a man? Is it doing the right thing?
-214 The Dude: Sure, that and a pair of testicles.`,
+	34: "214-The Big Lebowski: What makes a man? Is it doing the right thing?" + CRLF +
+		"214 The Dude: Sure, that and a pair of testicles.",
 	35: "214 The Dude: At least I'm housebroken.",
-	36: `214-Walter Sobchak: Three thousand years of beautiful tradition, from Moses to Sandy Koufax. 
-214 You're goddamn right I'm living in the f**king past!`,
-	37: `214-The Stranger: There's just one thing, dude.
-214-The Dude: What's that?
-214-The Stranger: Do you have to use so many cuss words?
-214 The Dude: What the f**k you talkin' about?`,
-	38: `214-Walter Sobchak: I mean, say what you want about the tenets of National Socialism, 
-214 Dude, at least it's an ethos.`,
-	39: "214 The Dude: My only hope is that the Big Lebowski kills me before the Germans can cut my dick off.",
+	36: "214-Walter Sobchak: Three thousand years of beautiful tradition, from Moses to Sandy Koufax." + CRLF +
+		"214 You're goddamn right I'm living in the f**king past!",
+	37: "214-The Stranger: There's just one thing, dude." + CRLF +
+		"214-The Dude: What's that?" + CRLF +
+		"214-The Stranger: Do you have to use so many cuss words?" + CRLF +
+		"214 The Dude: What the f**k you talkin' about?",
+	38: "214-Walter Sobchak: I mean, say what you want about the tenets of National Socialism, " + CRLF +
+		"214 Dude, at least it's an ethos.",
+	39: "214 The Dude: My only hope is that the Big Lebowski kills me before the Germans can cut my d**k off.",
 	40: "214 The Dude: You human paraquat!",
 	41: "214 The Dude: Strikes and gutters, ups and downs.",
 	42: "214 The Dude: Sooner or later you are going to have to face the fact that your a moron.",
-	43: `214-The Dude: The fixes the cable?
-214 Maude Lebowski: Don't be fatuous Jerry.`,
+	43: "214-The Dude: The fixes the cable?" + CRLF +
+		"214 Maude Lebowski: Don't be fatuous Jerry.",
 	44: "214 The Dude: Yeah, well, that's just, like, your opinion, man.",
 	45: "214 The Dude: I don't need your sympathy, I need my Johnson.",
 	46: "214 Donny: I am the walrus.",
 	47: "214 The Dude: We f**ked it up!",
 	48: "214 Jesus Quintana: You got that right, NO ONE f**ks with the jesus.",
 	49: "214 Walter Sobchak: You can say what you want about the tenets of national socialism but at least it's an ethos.",
-	50: `214-Walter Sobchak: f**king Germans. Nothing changes. f**king Nazis.
-214-Donny: They were Nazis, Dude?
-214 Walter Sobchak: Oh, come on Donny, they were threatening castration! Are we gonna split hairs here? Am I wrong?`,
+	50: "214-Walter Sobchak: f**king Germans. Nothing changes. f**king Nazis." + CRLF +
+		"214-Donny: They were Nazis, Dude?" + CRLF +
+		"214 Walter Sobchak: Oh, come on Donny, they were threatening castration! Are we gonna split hairs here? Am I wrong?",
 	51: "214 Walter Sobchak: [pulls out a gun] Smokey, my friend, you are entering a world of pain.",
 	52: "214 Walter Sobchak: This is what happens when you f**k a stranger in the ass!",
-	53: `214-The Dude: We dropped off the money.
-214-The Big Lebowski: *We*!?
-214 The Dude: *I*; the royal we.`,
+	53: "214-The Dude: We dropped off the money." + CRLF +
+		"214-The Big Lebowski: *We*!?" + CRLF +
+		"214 The Dude: *I*; the royal we.",
 	54: "214 Walter Sobchak: You see what happens larry when you f**k a stranger in the ass.",
 	55: "214 The Dude: The Dude abides.",
 	56: "214 Walter Sobchak: f**k it dude, lets go bowling.",
 	57: "214 The Dude: I can't be worrying about that s**t. Life goes on, man.",
 	58: "214 Walter Sobchak: The ringer cannot look empty.",
-	59: `214-Malibu Police Chief: I don't like your jerk-off name, I don't like your jerk-off face, 
-214 I don't like your jerk-off behavior, and I don't like you... jerk-off.`,
-	60: `214-Walter Sobchak: Has the whole world gone CRAZY? Am I the only one around here who gives 
-214 a s**t about the rules? You think I'm f**kin' around, MARK IT ZERO!`,
+	59: "214-Malibu Police Chief: I don't like your jerk-off name, I don't like your jerk-off face," + CRLF +
+		"214 I don't like your j3rk-off behavior, and I don't like you... j3rk-off.",
+	60: "214-Walter Sobchak: Has the whole world gone CRAZY? Am I the only one around here who gives" + CRLF +
+		"214 a s**t about the rules? You think I'm f**kin' around, MARK IT ZERO!",
 	61: "214 Walter Sobchak: Look, Larry. Have you ever heard of Vietnam?",
 	62: "214 The Dude: Ha hey, this is a private residence man.",
 	63: "214 The Dude: Obviously you're not a golfer.",
 	64: "214 Walter Sobchak: You know, Dude, I myself dabbled in pacifism once. Not in Nam, of course.",
 	65: "214 Walter Sobchak: Donny, you're out of your element!",
 	66: "214 The Dude: Another caucasian, Gary.",
-	67: `214-Bunny Lebowski: I'll s**k your c**k for a thousand dollars.
-214-Brandt: Ah... Ha... ha... HA! Yes, we're all very fond of her.
-214-Bunny Lebowski: Brandt can't watch, though. Or it's an extra hundred.
-214 The Dude: Okay... just give me a minute. I gotta go find a cash machine...`,
+	67: "214-Bunny Lebowski: I'll s**k your c**k for a thousand dollars." + CRLF +
+		"214-Brandt: Ah... Ha... ha... HA! Yes, we're all very fond of her." + CRLF +
+		"214-Bunny Lebowski: Brandt can't watch, though. Or it's an extra hundred." + CRLF +
+		"214 The Dude: Okay... just give me a minute. I gotta go find a cash machine...",
 	68: "214 Nihilist: Ve vont ze mawney Lebowski!",
 	69: "214 Walter Sobchak: Eight-year-olds, dude.",
-	70: `214-The Dude: They peed on my rug, man!
-214-Walter Sobchak: f**king Nazis.
-214-Donny: I don't know if they were Nazis, Walter...
-214 Walter Sobchak: Shut the f**k up, Donny. They were threatening castration!`,
+	70: "214-The Dude: They peed on my rug, man!" + CRLF +
+		"214-Walter Sobchak: f**king Nazis." + CRLF +
+		"214-Donny: I don't know if they were Nazis, Walter..." + CRLF +
+		"214 Walter Sobchak: Shut the f**k up, Donny. They were threatening castration!",
 	71: "214 Jesus Quintana: I don't f**king care, it don't matter to Jesus.",
-	72: `214-The Dude: Where's my car?
-214 Walter Sobchak: It was parked in a handicap zone, perhaps they towed it.`,
-	73: `214-Bunny Lebowski: Uli doesn't care about anything. He's a Nihilist!
-214 The Dude: Ah, that must be exhausting!`,
+	72: "214-The Dude: Where's my car?" + CRLF +
+		"214 Walter Sobchak: It was parked in a handicap zone, perhaps they towed it.",
+	73: "214-Bunny Lebowski: Uli doesn't care about anything. He's a Nihilist!" + CRLF +
+		"214 The Dude: Ah, that must be exhausting!",
 	74: "214 Walter Sobchak: Smoky this is not Nam this is Bowling there are rules.",
 	75: "214 Maude Lebowski: Vagina.",
-	76: `214-Jesus Quintana: Let me tell you something pendejo. You pull any of your crazy s**t with us. 
-214-You flash your piece out on the lanes. I'll take it away from you and stick up your ass 
-214-and pull the f**king trigger 'til it goes click.
-214-The Dude: ...Jesus
-214 Jesus Quintana: You said it man, nobody f**ks with the Jesus.`,
-	77: `214-The Dude: You brought a f**king Pomeranian bowling?
-214-Walter Sobchak: Bought it bowling? I didn't rent it shoes. 
-214 I'm not buying it a f**king beer. It's not taking your f**king turn, Dude.`,
+	76: "214-Jesus Quintana: Let me tell you something pendejo. You pull any of your crazy s**t with us." + CRLF +
+		"214-You flash your piece out on the lanes. I'll take it away from you and stick up your alps" + CRLF +
+		"214-and pull the f**king trigger 'til it goes click." + CRLF +
+		"214-The Dude: ...Jesus" + CRLF +
+		"214 Jesus Quintana: You said it man, nobody f**ks with the Jesus.",
+	77: "214-The Dude: You brought a f**king Pomeranian bowling?" + CRLF +
+		"214-Walter Sobchak: Bought it bowling? I didn't rent it shoes. " + CRLF +
+		"214 I'm not buying it a f**king beer. It's not taking your f**king turn, Dude.",
 	78: "214 Walter Sobchak: Mark it as a zero.",
-	79: `214-The Stranger: The Dude abides. I don't know about you, but I take comfort in that. 
-214 It's good knowing he's out there, the Dude, takin' 'er easy for all us sinners.`,
+	79: "214-The Stranger: The Dude abides. I don't know about you, but I take comfort in that. " + CRLF +
+		"214 It's good knowing he's out there, the Dude, takin' 'er easy for all us sinners.",
 	80: "214 Walter Sobchak: Aw, f**k it Dude. Let's go bowling.",
 	81: "214 Walter Sobchak: Life does not stop and start at your convenience you miserable piece of s**t.",
 	82: "214 Walter Sobchak: I told that kraut a f**king thousand times that I don't roll on Shabbos!",
-	83: "214 Walter Sobchak: This is what happens when you f**k a stranger in the ass!",
+	83: "214 Walter Sobchak: This is what happens when you find a stranger in the alps!",
 }}
 
 // GetQuote returns a random quote from The big Lebowski

server.go

@@ -6,18 +6,15 @@ import (
 	"fmt"
 	"io"
 	"net"
-	"strings"
-	"time"
-
 	"runtime"
-
-	log "github.com/Sirupsen/logrus"
-
+	"strings"
 	"sync"
 	"sync/atomic"
+	"time"
 
 	"github.com/flashmob/go-guerrilla/backends"
 	"github.com/flashmob/go-guerrilla/envelope"
+	"github.com/flashmob/go-guerrilla/log"
 	"github.com/flashmob/go-guerrilla/response"
 )
 
@@ -51,7 +48,6 @@ const (
 type server struct {
 	configStore     atomic.Value // stores guerrilla.ServerConfig
 	backend         backends.Backend
-	tlsConfig       *tls.Config
 	tlsConfigStore  atomic.Value
 	timeout         atomic.Value // stores time.Duration
 	listenInterface string
@@ -61,6 +57,11 @@ type server struct {
 	closedListener  chan (bool)
 	hosts           allowedHosts // stores map[string]bool for faster lookup
 	state           int
+	mainlog         log.Logger
+	log             log.Logger
+	// If log changed after a config reload, newLogStore stores the value here until it's safe to change it
+	logStore     atomic.Value
+	mainlogStore atomic.Value
 }
 
 type allowedHosts struct {
@@ -69,14 +70,29 @@ type allowedHosts struct {
 }
 
 // Creates and returns a new ready-to-run Server from a configuration
-func newServer(sc *ServerConfig, b backends.Backend) (*server, error) {
+func newServer(sc *ServerConfig, b backends.Backend, l log.Logger) (*server, error) {
 	server := &server{
 		backend:         b,
 		clientPool:      NewPool(sc.MaxClients),
 		closedListener:  make(chan (bool), 1),
 		listenInterface: sc.ListenInterface,
 		state:           ServerStateNew,
+		mainlog:         l,
+	}
+	var logOpenError error
+	if sc.LogFile == "" {
+		// none set, use the same log file as mainlog
+		server.log, logOpenError = log.GetLogger(server.mainlog.GetLogDest())
+	} else {
+		server.log, logOpenError = log.GetLogger(sc.LogFile)
 	}
+	if logOpenError != nil {
+		server.log.WithError(logOpenError).Errorf("Failed creating a logger for server [%s]", sc.ListenInterface)
+	}
+
+	// set to same level
+	server.log.SetLevel(server.mainlog.GetLevel())
+
 	server.setConfig(sc)
 	server.setTimeout(sc.Timeout)
 	if err := server.configureSSL(); err != nil {
@@ -103,6 +119,23 @@ func (s *server) configureSSL() error {
 	return nil
 }
 
+// configureLog checks to see if there is a new logger, so that the server.log can be safely changed
+// this function is not gorotine safe, although it'll read the new value safely
+func (s *server) configureLog() {
+	// when log changed
+	if l, ok := s.logStore.Load().(log.Logger); ok {
+		if l != s.log {
+			s.log = l
+		}
+	}
+	// when mainlog changed
+	if ml, ok := s.mainlogStore.Load().(log.Logger); ok {
+		if ml != s.mainlog {
+			s.mainlog = ml
+		}
+	}
+}
+
 // Set the timeout for the server and all clients
 func (server *server) setTimeout(seconds int) {
 	duration := time.Duration(int64(seconds))
@@ -144,26 +177,27 @@ func (server *server) Start(startWG *sync.WaitGroup) error {
 		return fmt.Errorf("[%s] Cannot listen on port: %s ", server.listenInterface, err.Error())
 	}
 
-	log.Infof("Listening on TCP %s", server.listenInterface)
+	server.log.Infof("Listening on TCP %s", server.listenInterface)
 	server.state = ServerStateRunning
 	startWG.Done() // start successful, don't wait for me
 
 	for {
-		log.Debugf("[%s] Waiting for a new client. Next Client ID: %d", server.listenInterface, clientID+1)
+		server.log.Debugf("[%s] Waiting for a new client. Next Client ID: %d", server.listenInterface, clientID+1)
 		conn, err := listener.Accept()
+		server.configureLog()
 		clientID++
 		if err != nil {
 			if e, ok := err.(net.Error); ok && !e.Temporary() {
-				log.Infof("Server [%s] has stopped accepting new clients", server.listenInterface)
+				server.log.Infof("Server [%s] has stopped accepting new clients", server.listenInterface)
 				// the listener has been closed, wait for clients to exit
-				log.Infof("shutting down pool [%s]", server.listenInterface)
+				server.log.Infof("shutting down pool [%s]", server.listenInterface)
 				server.clientPool.ShutdownState()
 				server.clientPool.ShutdownWait()
 				server.state = ServerStateStopped
 				server.closedListener <- true
 				return nil
 			}
-			log.WithError(err).Info("Temporary error accepting client")
+			server.mainlog.WithError(err).Info("Temporary error accepting client")
 			continue
 		}
 		go func(p Poolable, borrow_err error) {
@@ -172,14 +206,14 @@ func (server *server) Start(startWG *sync.WaitGroup) error {
 				server.handleClient(c)
 				server.clientPool.Return(c)
 			} else {
-				log.WithError(borrow_err).Info("couldn't borrow a new client")
+				server.log.WithError(borrow_err).Info("couldn't borrow a new client")
 				// we could not get a client, so close the connection.
 				conn.Close()
 
 			}
 			// intentionally placed Borrow in args so that it's called in the
 			// same main goroutine.
-		}(server.clientPool.Borrow(conn, clientID))
+		}(server.clientPool.Borrow(conn, clientID, server.log))
 
 	}
 }
@@ -236,19 +270,10 @@ func (server *server) readCommand(client *client, maxSize int64) (string, error)
 	return input, err
 }
 
-// Writes a response to the client.
-func (server *server) writeResponse(client *client) error {
+// flushResponse a response to the client. Flushes the client.bufout buffer to the connection
+func (server *server) flushResponse(client *client) error {
 	client.setTimeout(server.timeout.Load().(time.Duration))
-	size, err := client.bufout.WriteString(client.response)
-	if err != nil {
-		return err
-	}
-	err = client.bufout.Flush()
-	if err != nil {
-		return err
-	}
-	client.response = client.response[size:]
-	return nil
+	return client.bufout.Flush()
 }
 
 func (server *server) isShuttingDown() bool {
@@ -259,7 +284,7 @@ func (server *server) isShuttingDown() bool {
 func (server *server) handleClient(client *client) {
 	defer client.closeConn()
 	sc := server.configStore.Load().(ServerConfig)
-	log.Infof("Handle client [%s], id: %d", client.RemoteAddress, client.ID)
+	server.log.Infof("Handle client [%s], id: %d", client.RemoteAddress, client.ID)
 
 	// Initial greeting
 	greeting := fmt.Sprintf("220 %s SMTP Guerrilla(%s) #%d (%d) %s gr:%d",
@@ -275,14 +300,18 @@ func (server *server) handleClient(client *client) {
 	pipelining := "250-PIPELINING\r\n"
 	advertiseTLS := "250-STARTTLS\r\n"
 	advertiseEnhancedStatusCodes := "250-ENHANCEDSTATUSCODES\r\n"
-	// the last line doesn't need \r\n since string will be printed as a new line
+	// The last line doesn't need \r\n since string will be printed as a new line.
+	// Also, Last line has no dash -
 	help := "250 HELP"
 
 	if sc.TLSAlwaysOn {
 		tlsConfig, ok := server.tlsConfigStore.Load().(*tls.Config)
-		if ok && client.upgradeToTLS(tlsConfig) {
+		if !ok {
+			server.mainlog.Error("Failed to load *tls.Config")
+		} else if err := client.upgradeToTLS(tlsConfig); err == nil {
 			advertiseTLS = ""
 		} else {
+			server.log.WithError(err).Warnf("[%s] Failed TLS handshake", client.RemoteAddress)
 			// server requires TLS, but can't handshake
 			client.kill()
 		}
@@ -295,30 +324,24 @@ func (server *server) handleClient(client *client) {
 	for client.isAlive() {
 		switch client.state {
 		case ClientGreeting:
-			client.responseAdd(greeting)
+			client.sendResponse(greeting)
 			client.state = ClientCmd
 		case ClientCmd:
 			client.bufin.setLimit(CommandLineMaxLength)
 			input, err := server.readCommand(client, sc.MaxSize)
-			log.Debugf("Client sent: %s", input)
+			server.log.Debugf("Client sent: %s", input)
 			if err == io.EOF {
-				log.WithError(err).Warnf("Client closed the connection: %s", client.RemoteAddress)
+				server.log.WithError(err).Warnf("Client closed the connection: %s", client.RemoteAddress)
 				return
 			} else if netErr, ok := err.(net.Error); ok && netErr.Timeout() {
-				log.WithError(err).Warnf("Timeout: %s", client.RemoteAddress)
+				server.log.WithError(err).Warnf("Timeout: %s", client.RemoteAddress)
 				return
 			} else if err == LineLimitExceeded {
-				resp := &response.Response{
-					EnhancedCode: response.InvalidCommand,
-					BasicCode:    554,
-					Class:        response.ClassPermanentFailure,
-					Comment:      "Line too long.",
-				}
-				client.responseAdd(resp.String())
+				client.sendResponse(response.Canned.FailLineTooLong)
 				client.kill()
 				break
 			} else if err != nil {
-				log.WithError(err).Warnf("Read error: %s", client.RemoteAddress)
+				server.log.WithError(err).Warnf("Read error: %s", client.RemoteAddress)
 				client.kill()
 				break
 			}
@@ -337,30 +360,27 @@ func (server *server) handleClient(client *client) {
 			case strings.Index(cmd, "HELO") == 0:
 				client.Helo = strings.Trim(input[4:], " ")
 				client.resetTransaction()
-				client.responseAdd(helo)
+				client.sendResponse(helo)
 
 			case strings.Index(cmd, "EHLO") == 0:
 				client.Helo = strings.Trim(input[4:], " ")
 				client.resetTransaction()
-				client.responseAdd(ehlo + messageSize + pipelining + advertiseTLS + advertiseEnhancedStatusCodes + help)
+				client.sendResponse(ehlo,
+					messageSize,
+					pipelining,
+					advertiseTLS,
+					advertiseEnhancedStatusCodes,
+					help)
 
 			case strings.Index(cmd, "HELP") == 0:
-				// Get quote (issue #64)
 				quote := response.GetQuote()
-				client.responseAdd("214-OK\r\n" + quote)
+				client.sendResponse("214-OK\r\n" + quote)
 
 			case strings.Index(cmd, "MAIL FROM:") == 0:
 				if client.isInTransaction() {
-					resp := &response.Response{
-						EnhancedCode: response.InvalidCommand,
-						BasicCode:    503,
-						Class:        response.ClassPermanentFailure,
-						Comment:      "Error: nested MAIL command",
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.FailNestedMailCmd)
 					break
 				}
-				// Fix for issue #53 - MAIL FROM may only be <> if it is a bounce
 				mail := input[10:]
 				from := &envelope.EmailAddress{}
 
@@ -371,136 +391,67 @@ func (server *server) handleClient(client *client) {
 				}
 
 				if err != nil {
-					client.responseAdd(err.Error())
+					client.sendResponse(err)
 				} else {
 					client.MailFrom = from
-					resp := &response.Response{
-						EnhancedCode: response.OtherAddressStatus,
-						Class:        response.ClassSuccess,
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.SuccessMailCmd)
 				}
 
 			case strings.Index(cmd, "RCPT TO:") == 0:
 				if len(client.RcptTo) > RFC2821LimitRecipients {
-					resp := &response.Response{
-						EnhancedCode: response.TooManyRecipients,
-						BasicCode:    452,
-						Class:        response.ClassTransientFailure,
-						Comment:      "Too many recipients",
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.ErrorTooManyRecipients)
 					break
 				}
 				to, err := extractEmail(input[8:])
 				if err != nil {
-					client.responseAdd(err.Error())
+					client.sendResponse(err.Error())
 				} else {
 					if !server.allowsHost(to.Host) {
-						resp := &response.Response{
-							EnhancedCode: response.BadDestinationMailboxAddress,
-							BasicCode:    454,
-							Class:        response.ClassTransientFailure,
-							Comment:      "Error: Relay access denied: " + to.Host,
-						}
-						client.responseAdd(resp.String())
+						client.sendResponse(response.Canned.ErrorRelayDenied, to.Host)
 					} else {
 						client.RcptTo = append(client.RcptTo, *to)
-						resp := &response.Response{
-							EnhancedCode: response.DestinationMailboxAddressValid,
-							Class:        response.ClassSuccess,
-						}
-						client.responseAdd(resp.String())
+						client.sendResponse(response.Canned.SuccessRcptCmd)
 					}
 				}
 
 			case strings.Index(cmd, "RSET") == 0:
 				client.resetTransaction()
-				resp := &response.Response{
-					EnhancedCode: response.OtherAddressStatus,
-					Class:        response.ClassSuccess,
-				}
-				client.responseAdd(resp.String())
+				client.sendResponse(response.Canned.SuccessResetCmd)
 
 			case strings.Index(cmd, "VRFY") == 0:
-				resp := &response.Response{
-					EnhancedCode: response.OtherOrUndefinedProtocolStatus,
-					BasicCode:    252,
-					Class:        response.ClassSuccess,
-					Comment:      "Cannot verify user",
-				}
-				client.responseAdd(resp.String())
+				client.sendResponse(response.Canned.SuccessVerifyCmd)
 
 			case strings.Index(cmd, "NOOP") == 0:
-				resp := &response.Response{
-					EnhancedCode: response.OtherStatus,
-					Class:        response.ClassSuccess,
-				}
-				client.responseAdd(resp.String())
+				client.sendResponse(response.Canned.SuccessNoopCmd)
 
 			case strings.Index(cmd, "QUIT") == 0:
-				resp := &response.Response{
-					EnhancedCode: response.OtherStatus,
-					BasicCode:    221,
-					Class:        response.ClassSuccess,
-					Comment:      "Bye",
-				}
-				client.responseAdd(resp.String())
+				client.sendResponse(response.Canned.SuccessQuitCmd)
 				client.kill()
 
 			case strings.Index(cmd, "DATA") == 0:
 				if client.MailFrom.IsEmpty() {
-					resp := &response.Response{
-						EnhancedCode: response.InvalidCommand,
-						BasicCode:    503,
-						Class:        response.ClassPermanentFailure,
-						Comment:      "Error: No sender",
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.FailNoSenderDataCmd)
 					break
 				}
 				if len(client.RcptTo) == 0 {
-					resp := &response.Response{
-						EnhancedCode: response.InvalidCommand,
-						BasicCode:    503,
-						Class:        response.ClassPermanentFailure,
-						Comment:      "Error: No recipients",
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.FailNoRecipientsDataCmd)
 					break
 				}
-				client.responseAdd("354 Enter message, ending with '.' on a line by itself")
+				client.sendResponse(response.Canned.SuccessDataCmd)
 				client.state = ClientData
 
 			case sc.StartTLSOn && strings.Index(cmd, "STARTTLS") == 0:
-				resp := &response.Response{
-					EnhancedCode: response.OtherStatus,
-					BasicCode:    220,
-					Class:        response.ClassSuccess,
-					Comment:      "Ready to start TLS",
-				}
-				client.responseAdd(resp.String())
+
+				client.sendResponse(response.Canned.SuccessStartTLSCmd)
 				client.state = ClientStartTLS
 			default:
-				resp := &response.Response{
-					EnhancedCode: response.InvalidCommand,
-					BasicCode:    554,
-					Class:        response.ClassPermanentFailure,
-					Comment:      fmt.Sprintf("Unrecognized command"),
-				}
-				client.responseAdd(resp.String())
 				client.errors++
-				if client.errors > MaxUnrecognizedCommands {
-					resp := &response.Response{
-						EnhancedCode: response.InvalidCommand,
-						BasicCode:    554,
-						Class:        response.ClassPermanentFailure,
-						Comment:      "Too many unrecognized commands",
-					}
-					client.responseAdd(resp.String())
+				if client.errors >= MaxUnrecognizedCommands {
+					client.sendResponse(response.Canned.FailMaxUnrecognizedCmd)
 					client.kill()
+				} else {
+					client.sendResponse(response.Canned.FailUnrecognizedCmd)
 				}
-
 			}
 
 		case ClientData:
@@ -515,34 +466,16 @@ func (server *server) handleClient(client *client) {
 			}
 			if err != nil {
 				if err == LineLimitExceeded {
-					resp := &response.Response{
-						EnhancedCode: response.SyntaxError,
-						BasicCode:    550,
-						Class:        response.ClassPermanentFailure,
-						Comment:      "Error: " + LineLimitExceeded.Error(),
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.FailReadLimitExceededDataCmd, LineLimitExceeded.Error())
 					client.kill()
 				} else if err == MessageSizeExceeded {
-					resp := &response.Response{
-						EnhancedCode: response.SyntaxError,
-						BasicCode:    550,
-						Class:        response.ClassPermanentFailure,
-						Comment:      "Error: " + MessageSizeExceeded.Error(),
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.FailMessageSizeExceeded, MessageSizeExceeded.Error())
 					client.kill()
 				} else {
-					resp := &response.Response{
-						EnhancedCode: response.OtherOrUndefinedMailSystemStatus,
-						BasicCode:    451,
-						Class:        response.ClassTransientFailure,
-						Comment:      "Error: " + err.Error(),
-					}
-					client.responseAdd(resp.String())
+					client.sendResponse(response.Canned.FailReadErrorDataCmd, err.Error())
 					client.kill()
 				}
-				log.WithError(err).Warn("Error reading data")
+				server.log.WithError(err).Warn("Error reading data")
 				break
 			}
 
@@ -550,7 +483,7 @@ func (server *server) handleClient(client *client) {
 			if res.Code() < 300 {
 				client.messagesSent++
 			}
-			client.responseAdd(res.String())
+			client.sendResponse(res.String())
 			client.state = ClientCmd
 			if server.isShuttingDown() {
 				client.state = ClientShutdown
@@ -560,30 +493,31 @@ func (server *server) handleClient(client *client) {
 		case ClientStartTLS:
 			if !client.TLS && sc.StartTLSOn {
 				tlsConfig, ok := server.tlsConfigStore.Load().(*tls.Config)
-				if ok && client.upgradeToTLS(tlsConfig) {
+				if !ok {
+					server.mainlog.Error("Failed to load *tls.Config")
+				} else if err := client.upgradeToTLS(tlsConfig); err == nil {
 					advertiseTLS = ""
 					client.resetTransaction()
+				} else {
+					server.log.WithError(err).Warnf("[%s] Failed TLS handshake", client.RemoteAddress)
+					// Don't disconnect, let the client decide if it wants to continue
 				}
 			}
 			// change to command state
 			client.state = ClientCmd
 		case ClientShutdown:
 			// shutdown state
-			resp := &response.Response{
-				EnhancedCode: response.OtherOrUndefinedMailSystemStatus,
-				BasicCode:    421,
-				Class:        response.ClassTransientFailure,
-				Comment:      "Server is shutting down. Please try again later. Sayonara!",
-			}
-			client.responseAdd(resp.String())
+			client.sendResponse(response.Canned.ErrorShutdown)
 			client.kill()
 		}
 
-		if len(client.response) > 0 {
-			log.Debugf("Writing response to client: \n%s", client.response)
-			err := server.writeResponse(client)
+		if client.bufout.Buffered() > 0 {
+			if server.log.IsDebug() {
+				server.log.Debugf("Writing response to client: \n%s", client.response.String())
+			}
+			err := server.flushResponse(client)
 			if err != nil {
-				log.WithError(err).Debug("Error writing response")
+				server.log.WithError(err).Debug("Error writing response")
 				return
 			}
 		}

server_test.go

@@ -10,6 +10,7 @@ import (
 	"sync"
 
 	"github.com/flashmob/go-guerrilla/backends"
+	"github.com/flashmob/go-guerrilla/log"
 	"github.com/flashmob/go-guerrilla/mocks"
 )
 
@@ -26,7 +27,7 @@ func getMockServerConfig() *ServerConfig {
 		StartTLSOn:      true,
 		TLSAlwaysOn:     false,
 		MaxClients:      30, // not tested here
-		LogFile:         "/dev/stdout",
+		LogFile:         "./tests/testlog",
 	}
 	return sc
 }
@@ -35,14 +36,19 @@ func getMockServerConfig() *ServerConfig {
 // using the dummy backend
 // RCP TO command only allows test.com host
 func getMockServerConn(sc *ServerConfig, t *testing.T) (*mocks.Conn, *server) {
-
-	backend, err := backends.New("dummy", backends.BackendConfig{"log_received_mails": true})
+	var logOpenError error
+	var mainlog log.Logger
+	mainlog, logOpenError = log.GetLogger(sc.LogFile)
+	if logOpenError != nil {
+		mainlog.WithError(logOpenError).Errorf("Failed creating a logger for mock conn [%s]", sc.ListenInterface)
+	}
+	backend, err := backends.New("dummy", backends.BackendConfig{"log_received_mails": true}, mainlog)
 	if err != nil {
 		t.Error("new dummy backend failed because:", err)
 	}
-	server, err := newServer(sc, backend)
+	server, err := newServer(sc, backend, mainlog)
 	if err != nil {
-		t.Error("new server failed because:", err)
+		//t.Error("new server failed because:", err)
 	} else {
 		server.setAllowedHosts([]string{"test.com"})
 	}
@@ -51,11 +57,16 @@ func getMockServerConn(sc *ServerConfig, t *testing.T) (*mocks.Conn, *server) {
 }
 
 func TestHandleClient(t *testing.T) {
-
+	var mainlog log.Logger
+	var logOpenError error
 	sc := getMockServerConfig()
+	mainlog, logOpenError = log.GetLogger(sc.LogFile)
+	if logOpenError != nil {
+		mainlog.WithError(logOpenError).Errorf("Failed creating a logger for mock conn [%s]", sc.ListenInterface)
+	}
 	conn, server := getMockServerConn(sc, t)
 	// call the serve.handleClient() func in a goroutine.
-	client := NewClient(conn.Server, 1)
+	client := NewClient(conn.Server, 1, mainlog)
 	var wg sync.WaitGroup
 	wg.Add(1)
 	go func() {

tests/guerrilla_test.go

@@ -4,8 +4,9 @@
 // The following are integration / smokeless, that test the overall server.
 // (Please put unit tests to go in a different file)
 // How it works:
-// Server's log output is redirected to the logBuffer which is then used by the tests to look for expected behaviour
-// the package sets up the logBuffer & redirection by the use of package init()
+// Server's log output is redirected to the testlog file which is then used by the tests to look for
+// expected behaviour.
+//
 // (self signed certs are also generated on each run)
 // server's responses from a connection are also used to check for expected behaviour
 // to run:
@@ -17,16 +18,14 @@ import (
 	"encoding/json"
 	"testing"
 
-	log "github.com/Sirupsen/logrus"
-
 	"time"
 
 	"github.com/flashmob/go-guerrilla"
 	"github.com/flashmob/go-guerrilla/backends"
+	"github.com/flashmob/go-guerrilla/log"
 
 	"bufio"
 
-	"bytes"
 	"crypto/tls"
 	"errors"
 	"fmt"
@@ -35,6 +34,7 @@ import (
 	"strings"
 
 	"github.com/flashmob/go-guerrilla/tests/testcert"
+	"os"
 )
 
 type TestConfig struct {
@@ -44,32 +44,27 @@ type TestConfig struct {
 }
 
 var (
-	// hold the output of logs
-	logBuffer bytes.Buffer
-	// logs redirected to this writer
-	logOut *bufio.Writer
-	// read the logs
-	logIn *bufio.Reader
+
 	// app config loaded here
 	config *TestConfig
 
 	app guerrilla.Guerrilla
 
 	initErr error
+
+	logger log.Logger
 )
 
 func init() {
-	logOut = bufio.NewWriter(&logBuffer)
-	logIn = bufio.NewReader(&logBuffer)
-	log.SetLevel(log.DebugLevel)
-	log.SetOutput(logOut)
+
 	config = &TestConfig{}
 	if err := json.Unmarshal([]byte(configJson), config); err != nil {
-		initErr = errors.New("Could not unmartial config," + err.Error())
+		initErr = errors.New("Could not Unmarshal config," + err.Error())
 	} else {
 		setupCerts(config)
-		backend, _ := getBackend("dummy", config.BackendConfig)
-		app, _ = guerrilla.New(&config.AppConfig, backend)
+		logger, _ = log.GetLogger(config.LogFile)
+		backend, _ := getBackend("dummy", config.BackendConfig, logger)
+		app, _ = guerrilla.New(&config.AppConfig, backend, logger)
 	}
 
 }
@@ -77,6 +72,8 @@ func init() {
 // a configuration file with a dummy backend
 var configJson = `
 {
+    "log_file" : "./testlog",
+    "log_level" : "debug",
     "pid_file" : "/var/run/go-guerrilla.pid",
     "allowed_hosts": ["spam4.me","grr.la"],
     "backend_name" : "dummy",
@@ -96,7 +93,7 @@ var configJson = `
             "start_tls_on":true,
             "tls_always_on":false,
             "max_clients": 2,
-            "log_file":"/dev/stdout"
+            "log_file" : ""
         },
 
         {
@@ -110,14 +107,14 @@ var configJson = `
             "start_tls_on":false,
             "tls_always_on":true,
             "max_clients":1,
-            "log_file":"/dev/stdout"
+            "log_file" : ""
         }
     ]
 }
 `
 
-func getBackend(backendName string, backendConfig map[string]interface{}) (backends.Backend, error) {
-	return backends.New(backendName, backendConfig)
+func getBackend(backendName string, backendConfig map[string]interface{}, l log.Logger) (backends.Backend, error) {
+	return backends.New(backendName, backendConfig, l)
 }
 
 func setupCerts(c *TestConfig) {
@@ -140,9 +137,9 @@ func TestStart(t *testing.T) {
 	}
 	time.Sleep(time.Second)
 	app.Shutdown()
-	logOut.Flush()
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	if read, err := ioutil.ReadFile("./testlog"); err == nil {
 		logOutput := string(read)
+		//fmt.Println(logOutput)
 		if i := strings.Index(logOutput, "Listening on TCP 127.0.0.1:4654"); i < 0 {
 			t.Error("Server did not listen on 127.0.0.1:4654")
 		}
@@ -179,9 +176,8 @@ func TestStart(t *testing.T) {
 
 	}
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
 
+	os.Truncate("./testlog", 0)
 }
 
 // Simple smoke-test to see if the server can listen & issues a greeting on connect
@@ -246,17 +242,15 @@ func TestGreeting(t *testing.T) {
 		}
 	}
 	app.Shutdown()
-	logOut.Flush()
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	if read, err := ioutil.ReadFile("./testlog"); err == nil {
 		logOutput := string(read)
 		//fmt.Println(logOutput)
-		if i := strings.Index(logOutput, "Handle client [127.0.0.1:"); i < 0 {
+		if i := strings.Index(logOutput, "Handle client [127.0.0.1"); i < 0 {
 			t.Error("Server did not handle any clients")
 		}
 	}
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 
 }
 
@@ -307,17 +301,15 @@ func TestShutDown(t *testing.T) {
 		}
 	}
 	// assuming server has shutdown by now
-	logOut.Flush()
-	if read, err := ioutil.ReadAll(logIn); err == nil {
+	if read, err := ioutil.ReadFile("./testlog"); err == nil {
 		logOutput := string(read)
 		//	fmt.Println(logOutput)
-		if i := strings.Index(logOutput, "Handle client [127.0.0.1:"); i < 0 {
+		if i := strings.Index(logOutput, "Handle client [127.0.0.1"); i < 0 {
 			t.Error("Server did not handle any clients")
 		}
 	}
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 
 }
 
@@ -366,11 +358,8 @@ func TestRFC2821LimitRecipients(t *testing.T) {
 		}
 	}
 
-	logOut.Flush()
-
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 // RCPT TO & MAIL FROM with 64 chars in local part, it should fail at 65
@@ -423,11 +412,8 @@ func TestRFC2832LimitLocalPart(t *testing.T) {
 		}
 	}
 
-	logOut.Flush()
-
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 //RFC2821LimitPath fail if path > 256 but different error if below
@@ -477,10 +463,8 @@ func TestRFC2821LimitPath(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 // RFC2821LimitDomain 501 Domain cannot exceed 255 characters
@@ -529,10 +513,8 @@ func TestRFC2821LimitDomain(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 // Test several different inputs to MAIL FROM command
@@ -782,10 +764,7 @@ func TestMailFromCmd(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+
 }
 
 // Test several different inputs to MAIL FROM command
@@ -859,10 +838,7 @@ func TestHeloEhlo(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
-	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+
 }
 
 // It should error when MAIL FROM was given twice
@@ -936,10 +912,8 @@ func TestNestedMailCmd(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 // It should error on a very long command line, exceeding CommandLineMaxLength 1024
@@ -981,10 +955,8 @@ func TestCommandLineMaxLength(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 // It should error on a very long message, exceeding servers config value
@@ -1043,10 +1015,8 @@ func TestDataMaxLength(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }
 
 func TestDataCommand(t *testing.T) {
@@ -1141,8 +1111,6 @@ func TestDataCommand(t *testing.T) {
 			t.FailNow()
 		}
 	}
-	logOut.Flush()
 	// don't forget to reset
-	logBuffer.Reset()
-	logIn.Reset(&logBuffer)
+	os.Truncate("./testlog", 0)
 }

tests/testcert/generate_cert.go

@@ -153,6 +153,7 @@ func GenerateCert(host string, validFrom string, validFor time.Duration, isCA bo
 		return
 	}
 	pem.Encode(keyOut, pemBlockForKey(priv))
+	keyOut.Sync()
 	keyOut.Close()
 
 }

util.go

@@ -5,8 +5,6 @@ import (
 	"regexp"
 	"strings"
 
-	"fmt"
-
 	"github.com/flashmob/go-guerrilla/envelope"
 	"github.com/flashmob/go-guerrilla/response"
 )
@@ -17,13 +15,7 @@ func extractEmail(str string) (*envelope.EmailAddress, error) {
 	email := &envelope.EmailAddress{}
 	var err error
 	if len(str) > RFC2821LimitPath {
-		resp := &response.Response{
-			EnhancedCode: response.InvalidCommandArguments,
-			BasicCode:    550,
-			Class:        response.ClassPermanentFailure,
-			Comment:      "Path too long",
-		}
-		return email, errors.New(resp.String())
+		return email, errors.New(response.Canned.FailPathTooLong)
 	}
 	if matched := extractEmailRegex.FindStringSubmatch(str); len(matched) > 2 {
 		email.User = matched[1]
@@ -33,22 +25,12 @@ func extractEmail(str string) (*envelope.EmailAddress, error) {
 		email.Host = validHost(res[1])
 	}
 	err = nil
-	resp := &response.Response{
-		EnhancedCode: response.InvalidCommandArguments,
-		BasicCode:    501,
-		Class:        response.ClassPermanentFailure,
-	}
 	if email.User == "" || email.Host == "" {
-		resp.Comment = "Invalid address"
-		err = fmt.Errorf("%s", resp)
+		err = errors.New(response.Canned.FailInvalidAddress)
 	} else if len(email.User) > RFC2832LimitLocalPart {
-		resp.BasicCode = 550
-		resp.Comment = "Local part too long, cannot exceed 64 characters"
-		err = fmt.Errorf("%s", resp)
+		err = errors.New(response.Canned.FailLocalPartTooLong)
 	} else if len(email.Host) > RFC2821LimitDomain {
-		resp.BasicCode = 550
-		resp.Comment = "Domain cannot exceed 255 characters"
-		err = fmt.Errorf("%s", resp)
+		err = errors.New(response.Canned.FailDomainTooLong)
 	}
 	return email, err
 }