PLT-2058 Debugging incoming web hook content (#3150)

* PLT-2058 Debugging incoming web hook content

This change debugs contents of incoming webhooks using l4g.

The problem is that in order to debug the request body, it neads to be
read. And a Reader can only be read once. Hence, the body is only read
for Debugging if it is actually enabled. Furthermore, a new reader is
created from the content of the old reader in order for the rest of the
method to work as usual (with or without debugging).

The debug statement is wrapped in a closure, so that the content is
only copied if Debug is actually enabled.

It is not possible to return `(string, string)` from the closure to
`l4g.Debug()`. That is the reason the debugging is not done with `=%v`,
but the translations strings end with a space.

I tested the change with a `application/json` HTTP header as well as
`payload=`

The debug method is extracted into util/log.go in order to be re-usable
for debugging `io.Reader`

* Added a config flag to turn off incoming webhook debugging

Setting `EnableWebhookDebugging` to false in the `config.json` will
disable the printing of the content of incoming webhooks to the console

* Defaulting webhook debugging to true

* Added the setting of debugging incoming webhooks to the system console

api/webhook.go

@@ -4,6 +4,7 @@
 package api
 
 import (
+	"io"
 	"net/http"
 	"strings"
 
@@ -373,14 +374,33 @@ func incomingWebhook(c *Context, w http.ResponseWriter, r *http.Request) {
 
 	r.ParseForm()
 
-	var parsedRequest *model.IncomingWebhookRequest
+	var payload io.Reader
 	contentType := r.Header.Get("Content-Type")
 	if strings.Split(contentType, "; ")[0] == "application/x-www-form-urlencoded" {
-		parsedRequest = model.IncomingWebhookRequestFromJson(strings.NewReader(r.FormValue("payload")))
+		payload = strings.NewReader(r.FormValue("payload"))
 	} else {
-		parsedRequest = model.IncomingWebhookRequestFromJson(r.Body)
+		payload = r.Body
 	}
 
+	if utils.Cfg.LogSettings.EnableWebhookDebugging {
+		var err error
+		payload, err = utils.DebugReader(
+			payload,
+			utils.T("api.webhook.incoming.debug"),
+		)
+		if err != nil {
+			c.Err = model.NewLocAppError(
+				"incomingWebhook",
+				"api.webhook.incoming.debug.error",
+				nil,
+				err.Error(),
+			)
+			return
+		}
+	}
+
+	parsedRequest := model.IncomingWebhookRequestFromJson(payload)
+
 	if parsedRequest == nil {
 		c.Err = model.NewLocAppError("incomingWebhook", "web.incoming_webhook.parse.app_error", nil, "")
 		return

config/config.json

@@ -52,7 +52,8 @@
         "EnableFile": true,
         "FileLevel": "INFO",
         "FileFormat": "",
-        "FileLocation": ""
+        "FileLocation": "",
+        "EnableWebhookDebugging": true
     },
     "FileSettings": {
         "MaxFileSize": 52428800,

i18n/en.json

@@ -1955,6 +1955,14 @@
     "id": "api.webhook.get_outgoing.disabled.app_error",
     "translation": "Outgoing webhooks have been disabled by the system admin."
   },
+  {
+    "id": "api.webhook.incoming.debug",
+    "translation": "Incoming webhook received. Content="
+  },
+  {
+    "id": "api.webhook.incoming.debug.error",
+    "translation": "Could not read payload of incoming webhook."
+  },
   {
     "id": "api.webhook.init.debug",
     "translation": "Initializing webhook api routes"

model/config.go

@@ -83,12 +83,13 @@ type SqlSettings struct {
 }
 
 type LogSettings struct {
-	EnableConsole bool
-	ConsoleLevel  string
-	EnableFile    bool
-	FileLevel     string
-	FileFormat    string
-	FileLocation  string
+	EnableConsole          bool
+	ConsoleLevel           string
+	EnableFile             bool
+	FileLevel              string
+	FileFormat             string
+	FileLocation           string
+	EnableWebhookDebugging bool
 }
 
 type FileSettings struct {

utils/log.go

@@ -0,0 +1,33 @@
+// Copyright (c) 2015 Mattermost, Inc. All Rights Reserved.
+// See License.txt for license information.
+
+package utils
+
+import (
+	"bytes"
+	"io"
+	"io/ioutil"
+
+	l4g "github.com/alecthomas/log4go"
+)
+
+// DebugReader logs the content of the io.Reader and returns a new io.Reader
+// with the same content as the received io.Reader.
+// If you pass reader by reference, it won't be re-created unless the loglevel
+// includes Debug.
+// If an error is returned, the reader is consumed an cannot be read again.
+func DebugReader(reader io.Reader, message string) (io.Reader, error) {
+	var err error
+	l4g.Debug(func() string {
+		content, err := ioutil.ReadAll(reader)
+		if err != nil {
+			return ""
+		}
+
+		reader = bytes.NewReader(content)
+
+		return message + string(content)
+	})
+
+	return reader, err
+}

webapp/components/admin_console/log_settings.jsx

@@ -26,7 +26,8 @@ export default class LogSettings extends AdminSettings {
             enableFile: props.config.LogSettings.EnableFile,
             fileLevel: props.config.LogSettings.FileLevel,
             fileLocation: props.config.LogSettings.FileLocation,
-            fileFormat: props.config.LogSettings.FileFormat
+            fileFormat: props.config.LogSettings.FileFormat,
+            enableWebhookDebugging: props.config.LogSettings.EnableWebhookDebugging
         });
     }
 
@@ -37,6 +38,7 @@ export default class LogSettings extends AdminSettings {
         config.LogSettings.FileLevel = this.state.fileLevel;
         config.LogSettings.FileLocation = this.state.fileLocation;
         config.LogSettings.FileFormat = this.state.fileFormat;
+        config.LogSettings.EnableWebhookDebugging = this.state.enableWebhookDebugging;
 
         return config;
     }
@@ -166,6 +168,23 @@ export default class LogSettings extends AdminSettings {
                     onChange={this.handleChange}
                     disabled={!this.state.enableFile}
                 />
+                <BooleanSetting
+                    id='enableWebhookDebugging'
+                    label={
+                        <FormattedMessage
+                            id='admin.log.enableWebhookDebugging'
+                            defaultMessage='Enable Webhook Debugging:'
+                        />
+                    }
+                    helpText={
+                        <FormattedMessage
+                            id='admin.log.enableWebhookDebuggingDescription'
+                            defaultMessage='You can set this to false to disable the debug logging of all incoming webhook request bodies.'
+                        />
+                    }
+                    value={this.state.enableWebhookDebugging}
+                    onChange={this.handleChange}
+                />
             </SettingsGroup>
         );
     }

webapp/i18n/en.json

@@ -326,6 +326,8 @@
   "admin.log.logSettings": "Log Settings",
   "admin.logs.reload": "Reload",
   "admin.logs.title": "Server Logs",
+  "admin.log.enableWebhookDebugging": "Enable Webhook Debugging:",
+  "admin.log.enableWebhookDebuggingDescription": "You can set this to false to disable the debug logging of all incoming webhook request bodies.",
   "admin.nav.help": "Help",
   "admin.nav.logout": "Logout",
   "admin.nav.report": "Report a Problem",