Merge pull request #30 from appleboy/push/log

Fix #29 Add request and response log

.gitignore

@@ -29,4 +29,4 @@ config.yaml
 bin/*
 .DS_Store
 coverage.out
-logs/*
+gopush/log/*.log

README.md

@@ -1,9 +1,48 @@
 # Gopush
 
-A push notification server written in Go (Golang).
+A push notification server using [Gin](https://github.com/gin-gonic/gin) framework written in Go (Golang).
 
 [![Build Status](https://travis-ci.org/appleboy/gofight.svg?branch=master)](https://travis-ci.org/appleboy/gofight) [![Coverage Status](https://coveralls.io/repos/github/appleboy/gopush/badge.svg?branch=master)](https://coveralls.io/github/appleboy/gopush?branch=master) [![Go Report Card](https://goreportcard.com/badge/github.com/appleboy/gopush)](https://goreportcard.com/report/github.com/appleboy/gopush) [![codebeat badge](https://codebeat.co/badges/ee01d852-b5e8-465a-ad93-631d738818ff)](https://codebeat.co/projects/github-com-appleboy-gopush)
 
+## Feature
+
+* Support [Google Cloud Message](https://developers.google.com/cloud-messaging/) using [go-gcm](https://github.com/google/go-gcm) library for Android.
+* Support [HTTP/2](https://http2.github.io/) Apple Push Notification Service using [apns2](https://github.com/sideshow/apns2) library.
+* Support [YAML](https://github.com/go-yaml/yaml) configuration.
+
+See the [YAML config eample](config/config.yaml):
+
+```yaml
+core:
+  port: "8088"
+  notification_max: 100
+  mode: "release"
+  ssl: false
+  cert_path: "cert.pem"
+  key_path: "key.pem"
+
+api:
+  push_uri: "/api/push"
+  stat_go_uri: "/api/status"
+
+android:
+  enabled: false
+  apikey: ""
+
+ios:
+  enabled: false
+  pem_cert_path: "cert.pem"
+  pem_key_path: "key.pem"
+  production: false
+
+log:
+  format: "string" # string or json
+  access_log: "stdout"
+  access_level: "debug"
+  error_log: "stderr"
+  error_level: "error"
+```
+
 ## License
 
 Copyright 2016 Bo-Yi Wu [@appleboy](https://twitter.com/appleboy).

config/config.yaml

@@ -21,6 +21,7 @@ ios:
   production: false
 
 log:
+  format: "string" # string or json
   access_log: "stdout"
   access_level: "debug"
   error_log: "stderr"

gorush/config.go

@@ -41,6 +41,7 @@ type SectionIos struct {
 }
 
 type SectionLog struct {
+	Format      string `yaml:"format"`
 	AccessLog   string `yaml:"access_log"`
 	AccessLevel string `yaml:"access_level"`
 	ErrorLog    string `yaml:"error_log"`
@@ -73,6 +74,7 @@ func BuildDefaultPushConf() ConfYaml {
 	conf.Ios.Production = false
 
 	// log
+	conf.Log.Format = "string"
 	conf.Log.AccessLog = "stdout"
 	conf.Log.AccessLevel = "debug"
 	conf.Log.ErrorLog = "stderr"

gorush/const.go

@@ -8,3 +8,8 @@ const (
 	PlatFormIos = iota + 1
 	PlatFormAndroid
 )
+
+const (
+	StatusSucceededPush = "succeeded-push"
+	StatusFailedPush    = "failed-push"
+)

gorush/log.go

@@ -1,11 +1,57 @@
 package gopush
 
 import (
+	"encoding/json"
 	"errors"
+	"fmt"
 	"github.com/Sirupsen/logrus"
+	"github.com/gin-gonic/gin"
 	"os"
+	// "time"
 )
 
+var (
+	green   = string([]byte{27, 91, 57, 55, 59, 52, 50, 109})
+	white   = string([]byte{27, 91, 57, 48, 59, 52, 55, 109})
+	yellow  = string([]byte{27, 91, 57, 55, 59, 52, 51, 109})
+	red     = string([]byte{27, 91, 57, 55, 59, 52, 49, 109})
+	blue    = string([]byte{27, 91, 57, 55, 59, 52, 52, 109})
+	magenta = string([]byte{27, 91, 57, 55, 59, 52, 53, 109})
+	cyan    = string([]byte{27, 91, 57, 55, 59, 52, 54, 109})
+	reset   = string([]byte{27, 91, 48, 109})
+)
+
+type LogReq struct {
+	URI         string `json:"uri"`
+	Method      string `json:"method"`
+	IP          string `json:"ip"`
+	ContentType string `json:"content_type"`
+	Agent       string `json:"agent"`
+}
+
+type LogPushEntry struct {
+	Type     string `json:"type"`
+	Platform string `json:"platform"`
+	Token    string `json:"token"`
+	Message  string `json:"message"`
+	Error    string `json:"error"`
+
+	// Android
+	To                    string `json:"to,omitempty"`
+	CollapseKey           string `json:"collapse_key,omitempty"`
+	DelayWhileIdle        bool   `json:"delay_while_idle,omitempty"`
+	TimeToLive            uint   `json:"time_to_live,omitempty"`
+	RestrictedPackageName string `json:"restricted_package_name,omitempty"`
+	DryRun                bool   `json:"dry_run,omitempty"`
+
+	// iOS
+	ApnsID   string `json:"apns_id,omitempty"`
+	Topic    string `json:"topic,omitempty"`
+	Badge    int    `json:"badge,omitempty"`
+	Sound    string `json:"sound,omitempty"`
+	Category string `json:"category,omitempty"`
+}
+
 func InitLog() error {
 
 	var err error
@@ -15,11 +61,13 @@ func InitLog() error {
 	LogError = logrus.New()
 
 	LogAccess.Formatter = &logrus.TextFormatter{
+		TimestampFormat: "2006/01/02 - 15:04:05",
 		ForceColors:     true,
 		FullTimestamp:   true,
 	}
 
 	LogError.Formatter = &logrus.TextFormatter{
+		TimestampFormat: "2006/01/02 - 15:04:05",
 		ForceColors:     true,
 		FullTimestamp:   true,
 	}
@@ -74,3 +122,112 @@ func SetLogLevel(log *logrus.Logger, levelString string) error {
 
 	return nil
 }
+
+func LogRequest(uri string, method string, ip string, contentType string, agent string) {
+	var output string
+	log := &LogReq{
+		URI:         uri,
+		Method:      method,
+		IP:          ip,
+		ContentType: contentType,
+		Agent:       agent,
+	}
+
+	if PushConf.Log.Format == "json" {
+		logJson, _ := json.Marshal(log)
+
+		output = string(logJson)
+	} else {
+		// format is string
+		output = fmt.Sprintf("|%s header %s| %s %s %s %s %s",
+			magenta, reset,
+			log.Method,
+			log.URI,
+			log.IP,
+			log.ContentType,
+			log.Agent,
+		)
+	}
+
+	LogAccess.Info(output)
+}
+
+func colorForPlatForm(platform int) string {
+	switch platform {
+	case PlatFormIos:
+		return blue
+	case PlatFormAndroid:
+		return yellow
+	default:
+		return reset
+	}
+}
+
+func typeForPlatForm(platform int) string {
+	switch platform {
+	case PlatFormIos:
+		return "ios"
+	case PlatFormAndroid:
+		return "android"
+	default:
+		return ""
+	}
+}
+
+func LogPush(status, token string, req RequestPushNotification, errPush error) {
+	var plat, platColor, output string
+
+	platColor = colorForPlatForm(req.Platform)
+	plat = typeForPlatForm(req.Platform)
+
+	errMsg := ""
+	if errPush != nil {
+		errMsg = errPush.Error()
+	}
+
+	log := &LogPushEntry{
+		Type:     status,
+		Platform: plat,
+		Token:    token,
+		Message:  req.Message,
+		Error:    errMsg,
+	}
+
+	if PushConf.Log.Format == "json" {
+		logJson, _ := json.Marshal(log)
+
+		output = string(logJson)
+	} else {
+		switch status {
+		case StatusSucceededPush:
+			output = fmt.Sprintf("|%s %s %s| %s%s%s [%s] %s",
+				green, log.Type, reset,
+				platColor, log.Platform, reset,
+				log.Token,
+				log.Message,
+			)
+		case StatusFailedPush:
+			output = fmt.Sprintf("|%s %s %s| %s%s%s [%s] | %s | Error Message: %s",
+				red, log.Type, reset,
+				platColor, log.Platform, reset,
+				log.Token,
+				log.Message,
+				log.Error,
+			)
+		}
+	}
+
+	switch status {
+	case StatusSucceededPush:
+		LogAccess.Info(string(output))
+	case StatusFailedPush:
+		LogError.Error(string(output))
+	}
+}
+
+func LogMiddleware() gin.HandlerFunc {
+	return func(c *gin.Context) {
+		LogRequest(c.Request.URL.Path, c.Request.Method, c.ClientIP(), c.ContentType(), c.Request.Header.Get("User-Agent"))
+		c.Next()
+	}
+}

gorush/log_test.go

@@ -25,7 +25,7 @@ func TestSetLogOut(t *testing.T) {
 	err = SetLogOut(log, "stderr")
 	assert.Nil(t, err)
 
-	err = SetLogOut(log, "access.log")
+	err = SetLogOut(log, "log/access.log")
 	assert.Nil(t, err)
 
 	// missing create logs folder.
@@ -75,3 +75,15 @@ func TestErrorLogPath(t *testing.T) {
 
 	assert.NotNil(t, InitLog())
 }
+
+func TestPlatFormType(t *testing.T) {
+	assert.Equal(t, "ios", typeForPlatForm(PlatFormIos))
+	assert.Equal(t, "android", typeForPlatForm(PlatFormAndroid))
+	assert.Equal(t, "", typeForPlatForm(10000))
+}
+
+func TestPlatFormColor(t *testing.T) {
+	assert.Equal(t, blue, colorForPlatForm(PlatFormIos))
+	assert.Equal(t, yellow, colorForPlatForm(PlatFormAndroid))
+	assert.Equal(t, reset, colorForPlatForm(1000000))
+}

gorush/notification.go

@@ -2,11 +2,11 @@ package gopush
 
 import (
 	"errors"
+	"fmt"
 	"github.com/google/go-gcm"
 	apns "github.com/sideshow/apns2"
 	"github.com/sideshow/apns2/certificate"
 	"github.com/sideshow/apns2/payload"
-	"log"
 )
 
 type ExtendJSON struct {
@@ -67,9 +67,6 @@ type RequestPushNotification struct {
 	URLArgs  []string     `json:"url-args,omitempty"`
 	Extend   []ExtendJSON `json:"extend,omitempty"`
 	Alert    Alert        `json:"alert,omitempty"`
-
-	// meta
-	IDs []uint64 `json:"seq_id,omitempty"`
 }
 
 func CheckPushConf() error {
@@ -99,7 +96,7 @@ func InitAPNSClient() error {
 		CertificatePemIos, err = certificate.FromPemFile(PushConf.Ios.PemKeyPath, "")
 
 		if err != nil {
-			log.Println("Cert Error:", err)
+			LogError.Error("Cert Error:", err.Error())
 
 			return err
 		}
@@ -178,10 +175,9 @@ func GetIOSNotification(req RequestPushNotification) *apns.Notification {
 		payload.AlertTitleLocKey(req.Alert.TitleLocKey)
 	}
 
-	// Need send PR to apns2 repo.
+	if len(req.Alert.LocArgs) > 0 {
-	// if len(req.Alert.LocArgs) > 0 {
+		payload.AlertLocArgs(req.Alert.LocArgs)
-	// 	payload.AlertLocArgs(req.Alert.LocArgs)
+	}
-	// }
 
 	if len(req.Alert.TitleLocArgs) > 0 {
 		payload.AlertTitleLocArgs(req.Alert.TitleLocArgs)
@@ -233,13 +229,22 @@ func PushToIOS(req RequestPushNotification) bool {
 		res, err := ApnsClient.Push(notification)
 
 		if err != nil {
-			log.Println("There was an error: ", err)
+			// apns server error
+			LogPush(StatusFailedPush, token, req, err)
+
+			return false
+		}
+
+		if res.StatusCode != 200 {
+			// error message:
+			// ref: https://github.com/sideshow/apns2/blob/master/response.go#L14-L65
+			LogPush(StatusFailedPush, token, req, errors.New(res.Reason))
 
 			return false
 		}
 
 		if res.Sent() {
-			log.Println("APNs ID:", res.ApnsID)
+			LogPush(StatusSucceededPush, token, req, nil)
 		}
 	}
 
@@ -305,22 +310,22 @@ func PushToAndroid(req RequestPushNotification) bool {
 
 	res, err := gcm.SendHttp(PushConf.Android.ApiKey, notification)
 
-	log.Printf("Success count: %d, Failure count: %d", res.Success, res.Failure)
-
 	if err != nil {
-		log.Println("GCM Server Error Message: " + err.Error())
+		// GCM server error
+		LogError.Error("GCM server error: " + err.Error())
 
 		return false
 	}
 
-	if res.Error != "" {
+	LogAccess.Debug(fmt.Sprintf("Android Success count: %d, Failure count: %d", res.Success, res.Failure))
-		log.Println("GCM Http Error Message: " + res.Error)
 
-		return false
+	for k, result := range res.Results {
+		if result.Error != "" {
+			LogPush(StatusFailedPush, req.Tokens[k], req, errors.New(result.Error))
+			continue
 		}
 
-	if res.Success > 0 {
+		LogPush(StatusSucceededPush, req.Tokens[k], req, nil)
-		return true
 	}
 
 	return true

gorush/notification_test.go

@@ -156,6 +156,7 @@ func TestIOSAlertNotificationStructure(t *testing.T) {
 	aps := dat["aps"].(map[string]interface{})
 	alert := aps["alert"].(map[string]interface{})
 	titleLocArgs := alert["title-loc-args"].([]interface{})
+	locArgs := alert["loc-args"].([]interface{})
 
 	assert.Equal(t, test, action)
 	assert.Equal(t, test, actionLocKey)
@@ -166,6 +167,8 @@ func TestIOSAlertNotificationStructure(t *testing.T) {
 	assert.Equal(t, test, titleLocKey)
 	assert.Contains(t, titleLocArgs, "a")
 	assert.Contains(t, titleLocArgs, "b")
+	assert.Contains(t, locArgs, "a")
+	assert.Contains(t, locArgs, "b")
 }
 
 func TestAndroidNotificationStructure(t *testing.T) {

gorush/server.go

@@ -3,7 +3,6 @@ package gopush
 import (
 	api "github.com/appleboy/gin-status-api"
 	"github.com/gin-gonic/gin"
-	"log"
 	"net/http"
 )
 
@@ -25,7 +24,6 @@ func pushHandler(c *gin.Context) {
 	var form RequestPushNotification
 
 	if err := c.BindJSON(&form); err != nil {
-		log.Println(err)
 		AbortWithError(c, http.StatusBadRequest, "Bad input request, please refer to README guide.")
 		return
 	}
@@ -48,6 +46,7 @@ func GetMainEngine() *gin.Engine {
 	r.Use(gin.Logger())
 	r.Use(gin.Recovery())
 	r.Use(VersionMiddleware())
+	r.Use(LogMiddleware())
 
 	r.GET(PushConf.Api.StatGoUri, api.StatusHandler)
 	r.POST(PushConf.Api.PushUri, pushHandler)

gorush/server_test.go

@@ -62,6 +62,9 @@ func TestRootHandler(t *testing.T) {
 
 	r := gofight.New()
 
+	// log for json
+	PushConf.Log.Format = "json"
+
 	r.GET("/").
 		Run(GetMainEngine(), func(r gofight.HTTPResponse, rq gofight.HTTPRequest) {
 			data := []byte(r.Body.String())
@@ -197,11 +200,13 @@ func TestDisabledAndroidPushHandler(t *testing.T) {
 		})
 }
 
-func TestAndroidPushHandler(t *testing.T) {
+func TestHalfSuccessAndroidPushHandler(t *testing.T) {
 	initTest()
 
 	PushConf.Android.Enabled = true
 	PushConf.Android.ApiKey = os.Getenv("ANDROID_API_KEY")
+	// log for json
+	PushConf.Log.Format = "json"
 
 	android_token := os.Getenv("ANDROID_TEST_TOKEN")
 
@@ -218,3 +223,30 @@ func TestAndroidPushHandler(t *testing.T) {
 			assert.Equal(t, http.StatusOK, r.Code)
 		})
 }
+
+func TestAllSuccessAndroidPushHandler(t *testing.T) {
+	initTest()
+
+	PushConf.Android.Enabled = true
+	PushConf.Android.ApiKey = os.Getenv("ANDROID_API_KEY")
+	// log for json
+	PushConf.Log.Format = "json"
+
+	android_token := os.Getenv("ANDROID_TEST_TOKEN")
+
+	r := gofight.New()
+
+	r.POST("/api/push").
+		SetJSON(gofight.D{
+			"tokens":   []string{android_token, android_token},
+			"platform": 2,
+			"message":  "Welcome",
+		}).
+		Run(GetMainEngine(), func(r gofight.HTTPResponse, rq gofight.HTTPRequest) {
+
+			assert.Equal(t, http.StatusOK, r.Code)
+		})
+
+	// wait push response
+	time.Sleep(3000 * time.Millisecond)
+}