Improve error logging and debugging (#394)

CHANGELOG.md

@@ -1,6 +1,7 @@
 # Change Log
 
 - Fix field alignment issue [#393](https://github.com/hypermodeAI/runtime/pull/393)
+- Improve error logging and debugging [#394](https://github.com/hypermodeAI/runtime/pull/394)
 
 ## 2024-09-26 - Version 0.12.3
 

hostfunctions/log.go

@@ -6,6 +6,8 @@ package hostfunctions
 
 import (
 	"context"
+	"fmt"
+	"os"
 
 	"hypruntime/logger"
 	"hypruntime/utils"
@@ -17,17 +19,23 @@ func init() {
 
 func LogFunctionMessage(ctx context.Context, level, message string) {
 
+	// store messages in the context, so we can return them to the caller
+	messages := ctx.Value(utils.FunctionMessagesContextKey).(*[]utils.LogMessage)
+	*messages = append(*messages, utils.LogMessage{
+		Level:   level,
+		Message: message,
+	})
+
+	// If debugging, write debug messages to stderr instead of the logger
+	if level == "debug" && utils.HypermodeDebugEnabled() {
+		fmt.Fprintln(os.Stderr, message)
+		return
+	}
+
 	// write to the logger
 	logger.Get(ctx).
 		WithLevel(logger.ParseLevel(level)).
 		Str("text", message).
 		Bool("user_visible", true).
 		Msg("Message logged from function.")
-
-	// also store messages in the context, so we can return them to the caller
-	messages := ctx.Value(utils.FunctionMessagesContextKey).(*[]utils.LogMessage)
-	*messages = append(*messages, utils.LogMessage{
-		Level:   level,
-		Message: message,
-	})
 }

wasmhost/fncall.go

@@ -152,6 +152,7 @@ func (host *wasmHost) CallFunction(ctx context.Context, fnInfo functions.Functio
 			Bool("user_visible", true).
 			Msg("Function execution was canceled.")
 	} else {
+		// While debugging, it helps if we can see the error in the console without escaped newlines and other json formatting.
 		if utils.HypermodeDebugEnabled() {
 			fmt.Fprintln(os.Stderr, err)
 		}
@@ -161,6 +162,13 @@ func (host *wasmHost) CallFunction(ctx context.Context, fnInfo functions.Functio
 			Str("function", fnName).
 			Dur("duration_ms", duration).
 			Msg("Error while executing function.")
+
+		// However, we should still log _something_ that is user visible, so that the user knows something went wrong when they look at the function run logs.
+		logger.Error(ctx).
+			Str("function", fnName).
+			Dur("duration_ms", duration).
+			Bool("user_visible", true).
+			Msg("An internal runtime error occurred while executing the function.")
 	}
 
 	// Update metrics