process webhook in background; add SSH connection timeout; add timestamps to server logging

Author: Rutger van Deelen

cmd/server/server.go

@@ -5,6 +5,7 @@ import (
 	"log"
 	"net/http"
 	"os"
+	"strconv"
 
 	"github.com/Donders-Institute/hpc-webhook/internal/server"
 	"github.com/gorilla/mux"
@@ -26,6 +27,10 @@ func main() {
 	relayNode := os.Getenv("RELAY_NODE")
 	relayNodeTestUser := os.Getenv("RELAY_NODE_TEST_USER")
 	relayNodeTestUserPassword := os.Getenv("RELAY_NODE_TEST_USER_PASSWORD")
+	connectionTimeoutSeconds, err := strconv.Atoi(os.Getenv("CONNECTION_TIMEOUT_SECONDS"))
+	if err != nil {
+		panic(err)
+	}
 
 	// Set the database variables
 	host := os.Getenv("POSTGRES_HOST")
@@ -60,6 +65,7 @@ func main() {
 		RelayNode:                 relayNode,
 		RelayNodeTestUser:         relayNodeTestUser,
 		RelayNodeTestUserPassword: relayNodeTestUserPassword,
+		ConnectionTimeoutSeconds:  connectionTimeoutSeconds,
 		HPCWebhookHost:            hpcWebhookHost,
 		HPCWebhookInternalPort:    hpcWebhookInternalPort,
 		HPCWebhookExternalPort:    hpcWebhookExternalPort,

configs/hpc-webhook-database.env.example

@@ -9,6 +9,7 @@ PUBLIC_KEY_FILE=/run/secrets/hpc_webhook_public_key
 
 # Relay computer node settings
 RELAY_NODE=relaynode.dccn.nl
+CONNECTION_TIMEOUT_SECONDS=30
 
 # Database settings
 POSTGRES_HOST=localhost

docs/install.md

@@ -35,6 +35,7 @@ PUBLIC_KEY_FILE=/run/secrets/hpc_webhook_public_key
 
 # Relay computer node settings
 RELAY_NODE=relaynode.dccn.nl
+CONNECTION_TIMEOUT_SECONDS=30
 
 # Database settings
 POSTGRES_HOST=localhost

internal/server/execute.go

@@ -6,25 +6,27 @@ import (
 	"io/ioutil"
 	"net"
 	"os"
+	"time"
 
 	"golang.org/x/crypto/ssh"
 )
 
 type executeConfiguration struct {
-	privateKeyFilename     string
-	payloadFilename        string
-	targetPayloadDir       string
-	targetPayloadFilename  string
-	userScriptPathFilename string
-	relayNodeName          string
-	remoteServer           string
-	dataDir                string
-	homeDir                string
-	webhookID              string
-	payload                []byte
-	username               string
-	groupname              string
-	password               string
+	privateKeyFilename       string
+	payloadFilename          string
+	targetPayloadDir         string
+	targetPayloadFilename    string
+	userScriptPathFilename   string
+	relayNodeName            string
+	connectionTimeoutSeconds int
+	remoteServer             string
+	dataDir                  string
+	homeDir                  string
+	webhookID                string
+	payload                  []byte
+	username                 string
+	groupname                string
+	password                 string
 }
 
 // CopyFile copies a source file to a destination file.
@@ -87,6 +89,7 @@ func ExecuteScript(c Connector, conf executeConfiguration) error {
 		HostKeyCallback: func(hostname string, remote net.Addr, key ssh.PublicKey) error {
 			return nil
 		},
+		Timeout: time.Duration(conf.connectionTimeoutSeconds) * time.Second,
 	}
 
 	// Start an SSH session on the relay node

internal/server/execute_test.go

@@ -6,12 +6,14 @@ import (
 	"os"
 	"path"
 	"testing"
+	"time"
 
 	"golang.org/x/crypto/ssh"
 )
 
 func TestTriggerQsubCommand(t *testing.T) {
 	relayNodeName := "relaynode.dccn.nl"
+	connectionTimeoutSeconds := 30
 	remote := net.JoinHostPort(relayNodeName, "22")
 	webhookID := "550e8400-e29b-41d4-a716-446655440001"
 	username := "dccnuser"
@@ -99,6 +101,7 @@ func TestTriggerQsubCommand(t *testing.T) {
 		HostKeyCallback: func(hostname string, remote net.Addr, key ssh.PublicKey) error {
 			return nil
 		},
+		Timeout: time.Duration(connectionTimeoutSeconds) * time.Second,
 	}
 
 	client, err := fc.NewClient(remote, clientConfig)
@@ -108,18 +111,19 @@ func TestTriggerQsubCommand(t *testing.T) {
 	defer fc.CloseConnection(client)
 
 	executeConfig := executeConfiguration{
-		privateKeyFilename:     privateKeyFilename,
-		payloadFilename:        payloadFilename,
-		targetPayloadDir:       targetPayloadDir,
-		targetPayloadFilename:  targetPayloadFilename,
-		userScriptPathFilename: userScriptPathFilename,
-		username:               username,
-		groupname:              groupname,
-		password:               password,
-		relayNodeName:          relayNodeName,
-		webhookID:              webhookID,
-		dataDir:                dataDir,
-		homeDir:                homeDir,
+		privateKeyFilename:       privateKeyFilename,
+		payloadFilename:          payloadFilename,
+		targetPayloadDir:         targetPayloadDir,
+		targetPayloadFilename:    targetPayloadFilename,
+		userScriptPathFilename:   userScriptPathFilename,
+		username:                 username,
+		groupname:                groupname,
+		password:                 password,
+		relayNodeName:            relayNodeName,
+		connectionTimeoutSeconds: connectionTimeoutSeconds,
+		webhookID:                webhookID,
+		dataDir:                  dataDir,
+		homeDir:                  homeDir,
 	}
 
 	err = triggerQsubCommand(fc, client, executeConfig)

internal/server/server.go

@@ -22,6 +22,7 @@ type API struct {
 	RelayNode                 string
 	RelayNodeTestUser         string
 	RelayNodeTestUserPassword string
+	ConnectionTimeoutSeconds  int
 	HPCWebhookHost            string
 	HPCWebhookInternalPort    string // Port for internal use
 	HPCWebhookExternalPort    string // Port for the outside world

internal/server/webhook.go

@@ -9,6 +9,7 @@ import (
 	"os"
 	"path"
 	"strings"
+	"time"
 )
 
 // Webhook is an inbound github webhook
@@ -83,31 +84,40 @@ func parseWebhookRequest(req *http.Request) (*Webhook, string, error) {
 	return webhook, webhookID, err
 }
 
+// Process the webhook and log events
+func processWebhook(c Connector, conf executeConfiguration) {
+	err := ExecuteScript(c, conf)
+	if err != nil {
+		fmt.Printf("%s Error %s", time.Now().Format(time.RFC3339), err)
+	}
+	fmt.Printf("%s Success", time.Now().Format(time.RFC3339))
+}
+
 // WebhookHandler handles a HTTP POST request containing the webhook payload in its body
 func (a *API) WebhookHandler(w http.ResponseWriter, req *http.Request) {
 	// Check the method
 	if !strings.EqualFold(req.Method, "POST") {
 		w.WriteHeader(http.StatusMethodNotAllowed)
-		fmt.Printf("Error 405 - Method not allowed: invalid method: %s", req.Method)
 		fmt.Fprint(w, "Error 405 - Method not allowed: invalid method: ", req.Method)
+		fmt.Printf("%s Error 405 - Method not allowed: invalid method: %s", time.Now().Format(time.RFC3339), req.Method)
 		return
 	}
 
 	// Parse and validate the request
 	_, webhookID, err := parseWebhookRequest(req)
 	if err != nil {
 		w.WriteHeader(http.StatusNotFound)
-		fmt.Println(err)
 		fmt.Fprint(w, "Error 404 - Not found: ", err)
+		fmt.Printf("%s Error %s", time.Now().Format(time.RFC3339), err)
 		return
 	}
 
 	// Check if webhookID exists
 	groupname, username, err := checkWebhookID(a.DB, a.HPCWebhookHost, a.HPCWebhookExternalPort, webhookID)
 	if err != nil {
 		w.WriteHeader(http.StatusNotFound)
-		fmt.Println(err)
 		fmt.Fprint(w, "Error 404 - Not found: ", err)
+		fmt.Printf("%s Error %s", time.Now().Format(time.RFC3339), err)
 		return
 	}
 
@@ -117,6 +127,7 @@ func (a *API) WebhookHandler(w http.ResponseWriter, req *http.Request) {
 	if err != nil {
 		w.WriteHeader(http.StatusNotFound)
 		fmt.Fprint(w, "Error 404 - Not found: ", err)
+		fmt.Printf("%s Error %s", time.Now().Format(time.RFC3339), err)
 		return
 	}
 
@@ -125,8 +136,8 @@ func (a *API) WebhookHandler(w http.ResponseWriter, req *http.Request) {
 	err = os.MkdirAll(payloadDir, os.ModePerm)
 	if err != nil {
 		w.WriteHeader(http.StatusNotFound)
-		fmt.Println(err)
 		fmt.Fprint(w, "Error 404 - Not found: ", err)
+		fmt.Printf("%s Error %s", time.Now().Format(time.RFC3339), err)
 		return
 	}
 
@@ -135,6 +146,7 @@ func (a *API) WebhookHandler(w http.ResponseWriter, req *http.Request) {
 	if err != nil {
 		w.WriteHeader(http.StatusNotFound)
 		fmt.Fprint(w, "Error 404 - Not found: ", err)
+		fmt.Printf("%s Error %s", time.Now().Format(time.RFC3339), err)
 		return
 	}
 
@@ -160,17 +172,12 @@ func (a *API) WebhookHandler(w http.ResponseWriter, req *http.Request) {
 		payload:                payload,
 	}
 
-	// Execute the script
-	err = ExecuteScript(a.Connector, executeConfig)
-	if err != nil {
-		w.WriteHeader(http.StatusNotFound)
-		fmt.Fprint(w, "Error 404 - Not found: ", err)
-		return
-	}
+	// Process the webhook in the background
+	go processWebhook(a.Connector, executeConfig)
 
 	// Succes
 	w.WriteHeader(http.StatusOK)
-	fmt.Fprint(w, "Webhook handled successfully")
-
+	fmt.Fprint(w, "Payload delivered successfully")
+	fmt.Printf("%s Payload delivered successfully", time.Now().Format(time.RFC3339))
 	return
 }

internal/server/webhook_integration_test.go

@@ -56,7 +56,7 @@ func TestHandlerWebhook(t *testing.T) {
 				"x-github-delivery": "someValue",
 			},
 			expectedStatus: 200,
-			expectedString: "Webhook handled successfully",
+			expectedString: "Payload delivered successfully",
 			expectedResult: true, // No error
 		},
 		{
@@ -71,7 +71,7 @@ func TestHandlerWebhook(t *testing.T) {
 				"Content-Type": "application/json; charset=utf-8",
 			},
 			expectedStatus: 200,
-			expectedString: "Webhook handled successfully",
+			expectedString: "Payload delivered successfully",
 			expectedResult: true, // No error
 		},
 		{
@@ -86,7 +86,7 @@ func TestHandlerWebhook(t *testing.T) {
 				"Content-Type": "application/json; charset=utf-8",
 			},
 			expectedStatus: 200,
-			expectedString: "Webhook handled successfully",
+			expectedString: "Payload delivered successfully",
 			expectedResult: true, // No error
 		},
 		{
@@ -174,6 +174,7 @@ func TestHandlerWebhook(t *testing.T) {
 			RelayNode:                 "relaynode.dccn.nl",
 			RelayNodeTestUser:         c.username,
 			RelayNodeTestUserPassword: "somepassword",
+			ConnectionTimeoutSeconds:  30,
 			HPCWebhookHost:            "hpc-webhook.dccn.nl",
 			HPCWebhookInternalPort:    "5111",
 			HPCWebhookExternalPort:    "443",