switch to using chi instead of gorilla routing, add structured http l…

…ogging with context

backends/rapidpro/backend_test.go

@@ -79,6 +79,32 @@ func (ts *MsgTestSuite) TestCheckMsgExists() {
 	ts.Nil(err)
 }
 
+func (ts *MsgTestSuite) TestContact() {
+	knChannel := ts.getChannel("KN", "dbc126ed-66bc-4e28-b67b-81dc3327c95d")
+	urn := courier.NewTelURNForCountry("12065551518", "US")
+
+	now := time.Now()
+
+	// create our new contact
+	contact, err := contactForURN(ts.b.db, knChannel.OrgID(), knChannel.ID(), urn, "Ryan Lewis")
+	ts.NoError(err)
+
+	now2 := time.Now()
+
+	// load this contact again by URN, should be same contact, name unchanged
+	contact2, err := contactForURN(ts.b.db, knChannel.OrgID(), knChannel.ID(), urn, "Other Name")
+	ts.NoError(err)
+
+	ts.Equal(contact.UUID, contact2.UUID)
+	ts.Equal(contact.ID, contact2.ID)
+	ts.Equal(knChannel.OrgID(), contact2.OrgID)
+	ts.Equal("Ryan Lewis", contact2.Name)
+	ts.True(contact2.ModifiedOn.After(now))
+	ts.True(contact2.CreatedOn.After(now))
+	ts.True(contact2.ModifiedOn.Before(now2))
+	ts.True(contact2.CreatedOn.Before(now2))
+}
+
 func (ts *MsgTestSuite) TestContactURN() {
 	knChannel := ts.getChannel("KN", "dbc126ed-66bc-4e28-b67b-81dc3327c95d")
 	twChannel := ts.getChannel("TW", "dbc126ed-66bc-4e28-b67b-81dc3327c96a")

backends/rapidpro/contact.go

@@ -37,7 +37,7 @@ func insertContact(db *sqlx.DB, contact *DBContact) error {
 }
 
 const lookupContactFromURNSQL = `
-SELECT c.org_id, c.id, c.uuid, c.name, u.id as "urn_id"
+SELECT c.org_id, c.id, c.uuid, c.modified_on, c.created_on, c.name, u.id as "urn_id"
 FROM contacts_contact AS c, contacts_contacturn AS u 
 WHERE u.urn = $1 AND u.contact_id = c.id AND u.org_id = $2 AND c.is_active = TRUE AND c.is_test = FALSE
 `
@@ -60,6 +60,8 @@ func contactForURN(db *sqlx.DB, org OrgID, channelID ChannelID, urn courier.URN,
 	contact.OrgID = org
 	contact.UUID = uuid.NewV4().String()
 	contact.Name = name
+	contact.CreatedOn = time.Now()
+	contact.ModifiedOn = time.Now()
 
 	// TODO: Set these to a system user
 	contact.CreatedBy = 1

cmd/courier/main.go

@@ -22,21 +22,22 @@ import (
 	_ "github.com/nyaruka/courier/backends/rapidpro"
 )
 
-var version = "master"
+var version = "Dev"
 
 func main() {
 	m := config.NewWithPath("courier.toml")
 	config := &config.Courier{}
-
-	log.Println("Starting version: ", version)
-
 	err := m.Load(config)
 	if err != nil {
 		log.Fatalf("Error loading configuration: %s", err)
 	}
 
+	// if we have a custom version, use it
+	if version != "Dev" {
+		config.Version = version
+	}
+
 	// configure our logger
-	//logrus.SetFormatter(&logrus.JSONFormatter{})
 	logrus.SetOutput(os.Stdout)
 	level, err := logrus.ParseLevel(config.LogLevel)
 	if err != nil {

config/courier.go

@@ -21,13 +21,15 @@ type Courier struct {
 	AWSAccessKeyID     string `default:"missing_aws_access_key_id"`
 	AWSSecretAccessKey string `default:"missing_aws_secret_access_key"`
 
-	RapidproHandleURL string `default:"https://app.rapidpro.io/handlers/mage/handle_message/"`
+	RapidproHandleURL string `default:"https://app.rapidpro.io/handlers/mage/handle_message"`
 	RapidproToken     string `default:"missing_rapidpro_token"`
 
 	LogLevel string `default:"error"`
 
 	IncludeChannels []string
 	ExcludeChannels []string
+
+	Version string `default:"Dev"`
 }
 
 // NewWithPath returns a new instance of Loader to read from the given configuration file using our config options

handlers/africastalking/handler.go

@@ -46,13 +46,11 @@ var statusMapping = map[string]courier.MsgStatus{
 // Initialize is called by the engine once everything is loaded
 func (h *handler) Initialize(s courier.Server) error {
 	h.SetServer(s)
-	route := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
-	if route.GetError() != nil {
-		return route.GetError()
+	err := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
+	if err != nil {
+		return err
 	}
-
-	route = s.AddChannelRoute(h, "POST", "status", h.StatusMessage)
-	return route.GetError()
+	return s.AddChannelRoute(h, "POST", "status", h.StatusMessage)
 }
 
 // ReceiveMessage is our HTTP handler function for incoming messages
@@ -83,7 +81,7 @@ func (h *handler) ReceiveMessage(channel courier.Channel, w http.ResponseWriter,
 		return err
 	}
 
-	return courier.WriteReceiveSuccess(w, msg)
+	return courier.WriteReceiveSuccess(w, r, msg)
 }
 
 // StatusMessage is our HTTP handler function for status updates
@@ -108,5 +106,5 @@ func (h *handler) StatusMessage(channel courier.Channel, w http.ResponseWriter,
 		return err
 	}
 
-	return courier.WriteStatusSuccess(w, status)
+	return courier.WriteStatusSuccess(w, r, status)
 }

handlers/blackmyna/handler.go

@@ -24,13 +24,12 @@ func init() {
 // Initialize is called by the engine once everything is loaded
 func (h *bmHandler) Initialize(s courier.Server) error {
 	h.SetServer(s)
-	route := s.AddChannelRoute(h, "GET", "receive", h.ReceiveMessage)
-	if route.GetError() != nil {
-		return route.GetError()
+	err := s.AddChannelRoute(h, "GET", "receive", h.ReceiveMessage)
+	if err != nil {
+		return err
 	}
 
-	route = s.AddChannelRoute(h, "GET", "status", h.StatusMessage)
-	return route.GetError()
+	return s.AddChannelRoute(h, "GET", "status", h.StatusMessage)
 }
 
 // ReceiveMessage is our HTTP handler function for incoming messages
@@ -54,7 +53,7 @@ func (h *bmHandler) ReceiveMessage(channel courier.Channel, w http.ResponseWrite
 		return err
 	}
 
-	return courier.WriteReceiveSuccess(w, msg)
+	return courier.WriteReceiveSuccess(w, r, msg)
 }
 
 type bmMessage struct {
@@ -92,7 +91,7 @@ func (h *bmHandler) StatusMessage(channel courier.Channel, w http.ResponseWriter
 		return err
 	}
 
-	return courier.WriteStatusSuccess(w, status)
+	return courier.WriteStatusSuccess(w, r, status)
 }
 
 type bmStatus struct {

handlers/kannel/handler.go

@@ -25,13 +25,12 @@ func NewHandler() courier.ChannelHandler {
 // Initialize is called by the engine once everything is loaded
 func (h *kannelHandler) Initialize(s courier.Server) error {
 	h.SetServer(s)
-	route := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
-	if route.GetError() != nil {
-		return route.GetError()
+	err := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
+	if err != nil {
+		return err
 	}
 
-	route = s.AddChannelRoute(h, "GET", "status", h.StatusMessage)
-	return route.GetError()
+	return s.AddChannelRoute(h, "GET", "status", h.StatusMessage)
 }
 
 // ReceiveMessage is our HTTP handler function for incoming messages
@@ -58,7 +57,7 @@ func (h *kannelHandler) ReceiveMessage(channel courier.Channel, w http.ResponseW
 		return err
 	}
 
-	return courier.WriteReceiveSuccess(w, msg)
+	return courier.WriteReceiveSuccess(w, r, msg)
 }
 
 type kannelMessage struct {
@@ -97,7 +96,7 @@ func (h *kannelHandler) StatusMessage(channel courier.Channel, w http.ResponseWr
 		return err
 	}
 
-	return courier.WriteStatusSuccess(w, status)
+	return courier.WriteStatusSuccess(w, r, status)
 }
 
 type kannelStatus struct {

handlers/telegram/handler.go

@@ -30,8 +30,7 @@ func NewHandler() courier.ChannelHandler {
 // Initialize is called by the engine once everything is loaded
 func (h *telegramHandler) Initialize(s courier.Server) error {
 	h.SetServer(s)
-	route := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
-	return route.GetError()
+	return s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
 }
 
 // ReceiveMessage is our HTTP handler function for incoming messages
@@ -44,7 +43,7 @@ func (h *telegramHandler) ReceiveMessage(channel courier.Channel, w http.Respons
 
 	// no message? ignore this
 	if te.Message.MessageID == 0 {
-		return courier.WriteIgnored(w, "Ignoring request, no message")
+		return courier.WriteIgnored(w, r, "Ignoring request, no message")
 	}
 
 	// create our date from the timestamp
@@ -114,7 +113,7 @@ func (h *telegramHandler) ReceiveMessage(channel courier.Channel, w http.Respons
 		return err
 	}
 
-	return courier.WriteReceiveSuccess(w, msg)
+	return courier.WriteReceiveSuccess(w, r, msg)
 }
 
 var telegramAPIURL = "https://api.telegram.org"

handlers/twilio/handler.go

@@ -44,13 +44,12 @@ func init() {
 // Initialize is called by the engine once everything is loaded
 func (h *twHandler) Initialize(s courier.Server) error {
 	h.SetServer(s)
-	route := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
-	if route.GetError() != nil {
-		return route.GetError()
+	err := s.AddChannelRoute(h, "POST", "receive", h.ReceiveMessage)
+	if err != nil {
+		return err
 	}
 
-	route = s.AddChannelRoute(h, "POST", "status", h.StatusMessage)
-	return route.GetError()
+	return s.AddChannelRoute(h, "POST", "status", h.StatusMessage)
 }
 
 type twMessage struct {
@@ -145,7 +144,7 @@ func (h *twHandler) StatusMessage(channel courier.Channel, w http.ResponseWriter
 		return err
 	}
 
-	return courier.WriteStatusSuccess(w, status)
+	return courier.WriteStatusSuccess(w, r, status)
 }
 
 // Twilio expects Twiml from a message receive request

responses.go

@@ -6,11 +6,15 @@ import (
 	"net/http"
 	"strings"
 
+	"github.com/pressly/lg"
+
 	validator "gopkg.in/go-playground/validator.v9"
 )
 
 // WriteError writes a JSON response for the passed in error
-func WriteError(w http.ResponseWriter, err error) error {
+func WriteError(w http.ResponseWriter, r *http.Request, err error) error {
+	lg.Log(r.Context()).WithError(err).Error()
+
 	errors := []string{err.Error()}
 
 	vErrs, isValidation := err.(validator.ValidationErrors)
@@ -20,21 +24,29 @@ func WriteError(w http.ResponseWriter, err error) error {
 			errors = append(errors, fmt.Sprintf("field '%s' %s", strings.ToLower(vErrs[i].Field()), vErrs[i].Tag()))
 		}
 	}
-	return writeResponse(w, http.StatusBadRequest, &errorResponse{errors})
+	return writeJSONResponse(w, http.StatusBadRequest, &errorResponse{errors})
 }
 
 // WriteIgnored writes a JSON response for the passed in message
-func WriteIgnored(w http.ResponseWriter, message string) error {
+func WriteIgnored(w http.ResponseWriter, r *http.Request, message string) error {
+	lg.Log(r.Context()).Info("ignored message")
 	return writeData(w, http.StatusOK, message, struct{}{})
 }
 
 // WriteReceiveSuccess writes a JSON response for the passed in msg indicating we handled it
-func WriteReceiveSuccess(w http.ResponseWriter, msg *Msg) error {
+func WriteReceiveSuccess(w http.ResponseWriter, r *http.Request, msg *Msg) error {
+	lg.Log(r.Context()).WithField("msg_uuid", msg.UUID).Info("message received")
 	return writeData(w, http.StatusOK, "Message Accepted", &receiveData{msg.UUID})
 }
 
 // WriteStatusSuccess writes a JSON response for the passed in status update indicating we handled it
-func WriteStatusSuccess(w http.ResponseWriter, status *MsgStatusUpdate) error {
+func WriteStatusSuccess(w http.ResponseWriter, r *http.Request, status *MsgStatusUpdate) error {
+	if status.ID != NilMsgID {
+		lg.Log(r.Context()).WithField("msg_id", status.ID).Info("status updated")
+	} else {
+		lg.Log(r.Context()).WithField("msg_id", status.ExternalID).Info("status updated")
+	}
+
 	return writeData(w, http.StatusOK, "Status Update Accepted", &statusData{status.Status})
 }
 
@@ -55,12 +67,12 @@ type statusData struct {
 	Status MsgStatus `json:"status"`
 }
 
-func writeResponse(w http.ResponseWriter, statusCode int, response interface{}) error {
+func writeJSONResponse(w http.ResponseWriter, statusCode int, response interface{}) error {
 	w.Header().Set("Content-Type", "application/json")
 	w.WriteHeader(statusCode)
 	return json.NewEncoder(w).Encode(response)
 }
 
 func writeData(w http.ResponseWriter, statusCode int, message string, response interface{}) error {
-	return writeResponse(w, statusCode, &successResponse{message, response})
+	return writeJSONResponse(w, statusCode, &successResponse{message, response})
 }