Devmode: Improved logging output and sourcemap support

.github/workflows/release.yml

@@ -13,7 +13,7 @@ permissions:
 
 jobs:
   release:
-    runs-on: windows-latest # required to use wix
+    runs-on: blacksmith-4vcpu-ubuntu-2204
     steps:
       - name: Checkout
         uses: actions/checkout@v4

cmd/dev.go

@@ -124,9 +124,10 @@ Examples:
 
 		defer ui.Close(false)
 
-		tuiLogger := dev.NewTUILogger(logLevel, ui)
+		tuiLogger := dev.NewTUILogger(logLevel, ui, dev.Stdout)
+		tuiLoggerErr := dev.NewTUILogger(logLevel, ui, dev.StdErr)
 
-		if err := server.Connect(ui, tuiLogger); err != nil {
+		if err := server.Connect(ui, tuiLogger, tuiLoggerErr); err != nil {
 			log.Error("failed to start live dev connection: %s", err)
 			ui.Close(true)
 			return
@@ -139,7 +140,7 @@ Examples:
 			agent.PublicURL = fmt.Sprintf("%s/%s", publicUrl, agent.ID)
 		}
 
-		projectServerCmd, err := dev.CreateRunProjectCmd(processCtx, tuiLogger, theproject, server, dir, orgId, port, tuiLogger)
+		projectServerCmd, err := dev.CreateRunProjectCmd(processCtx, tuiLogger, theproject, server, dir, orgId, port, tuiLogger, tuiLoggerErr)
 		if err != nil {
 			errsystem.New(errsystem.ErrInvalidConfiguration, err, errsystem.WithContextMessage("Failed to run project")).ShowErrorAndExit()
 		}
@@ -241,7 +242,7 @@ Examples:
 				if isDeliberateRestart {
 					isDeliberateRestart = false
 					tuiLogger.Trace("restarting project server")
-					projectServerCmd, err = dev.CreateRunProjectCmd(processCtx, tuiLogger, theproject, server, dir, orgId, port, tuiLogger)
+					projectServerCmd, err = dev.CreateRunProjectCmd(processCtx, tuiLogger, theproject, server, dir, orgId, port, tuiLogger, tuiLoggerErr)
 					if err != nil {
 						errsystem.New(errsystem.ErrInvalidConfiguration, err, errsystem.WithContextMessage("Failed to run project")).ShowErrorAndExit()
 					}

internal/bundler/bundler.go

@@ -42,6 +42,21 @@ type BundleContext struct {
 	Writer     io.Writer
 }
 
+func installSourceMapSupportIfNeeded(ctx BundleContext, dir string) error {
+	// only bun needs to install this library to aide in parsing the source maps
+	path := filepath.Join(dir, "node_modules", "source-map-js", "package.json")
+	if !util.Exists(path) {
+		cmd := exec.CommandContext(ctx.Context, "bun", "add", "source-map-js", "--no-save", "--silent", "--no-progress", "--no-summary", "--ignore-scripts")
+		cmd.Dir = dir
+		out, err := cmd.CombinedOutput()
+		if err != nil {
+			return fmt.Errorf("failed to install source-map-js: %w. %s", err, string(out))
+		}
+		return nil
+	}
+	return nil
+}
+
 func bundleJavascript(ctx BundleContext, dir string, outdir string, theproject *project.Project) error {
 
 	if ctx.Install || !util.Exists(filepath.Join(dir, "node_modules")) {
@@ -79,6 +94,12 @@ func bundleJavascript(ctx BundleContext, dir string, outdir string, theproject *
 		ctx.Logger.Debug("installed dependencies: %s", strings.TrimSpace(string(out)))
 	}
 
+	if theproject.Bundler.Runtime == "bunjs" {
+		if err := installSourceMapSupportIfNeeded(ctx, dir); err != nil {
+			return fmt.Errorf("failed to install bun source-map-support: %w", err)
+		}
+	}
+
 	if err := checkForBreakingChanges(ctx, "javascript", theproject.Bundler.Runtime); err != nil {
 		return err
 	}
@@ -130,6 +151,12 @@ func bundleJavascript(ctx BundleContext, dir string, outdir string, theproject *
 	}
 	defines["process.env.AGENTUITY_CLOUD_AGENTS_JSON"] = cstr.JSONStringify(cstr.JSONStringify(agents))
 
+	var postShim string
+	// only bun needs this shim
+	if theproject.Bundler.Runtime == "bunjs" {
+		postShim = sourceMapShim
+	}
+
 	ctx.Logger.Debug("starting build")
 	started := time.Now()
 	result := api.Build(api.BuildOptions{
@@ -138,7 +165,7 @@ func bundleJavascript(ctx BundleContext, dir string, outdir string, theproject *
 		Outdir:         outdir,
 		Write:          true,
 		Splitting:      false,
-		Sourcemap:      api.SourceMapExternal,
+		Sourcemap:      api.SourceMapLinked,
 		SourcesContent: api.SourcesContentInclude,
 		Format:         api.FormatESModule,
 		Platform:       api.PlatformNode,
@@ -153,7 +180,7 @@ func bundleJavascript(ctx BundleContext, dir string, outdir string, theproject *
 		Define:        defines,
 		LegalComments: api.LegalCommentsNone,
 		Banner: map[string]string{
-			"js": jsheader + jsshim,
+			"js": strings.Join([]string{jsheader, jsshim, postShim}, "\n"),
 		},
 	})
 	ctx.Logger.Debug("finished build in %v", time.Since(started))

internal/bundler/shim.go

@@ -7,6 +7,7 @@ import { createRequire as __agentuity_createRequire } from 'module';
 const require = __agentuity_createRequire(import.meta.url);
 import { fileURLToPath as __agentuity_fileURLToPath } from 'url';
 import { dirname as __agentuity_dirname } from 'path';
+import { readFileSync as __agentuity_readFileSync, existsSync as __agentuity_existsSync } from 'fs';
 
 const __filename = __agentuity_fileURLToPath(import.meta.url);
 const __dirname = __agentuity_dirname(__filename);
@@ -45,4 +46,62 @@ globalThis.__require = (id) => {
 		}
 	}
 	throw new Error('Dynamic require of ' + id + ' is not supported');
-};`
+};
+`
+
+// NOTE: this shim is only used in bun since node has built-in source map support
+var sourceMapShim = `
+(function () {
+const { SourceMapConsumer: __agentuity_SourceMapConsumer } = require('source-map-js');
+const { join: __agentuity_join } = require('path');
+const __prepareStackTrace = Error.prepareStackTrace;
+const __cachedSourceMap = {};
+function getSourceMap(filename) {
+	if (filename in __cachedSourceMap) {
+		return __cachedSourceMap[filename];
+	}
+	if (!__agentuity_existsSync(filename)) {
+		return null;
+	}
+	const sm = new __agentuity_SourceMapConsumer(__agentuity_readFileSync(filename).toString());
+	__cachedSourceMap[filename] = sm;
+	return sm;
+}
+const frameRegex = /(.+)\((.+):(\d+):(\d+)\)$/;
+Error.prepareStackTrace = function (err, stack) {
+	const _stack = __prepareStackTrace(err, stack);
+	const tok = _stack.split('\n');
+	const lines = [];
+	for (const t of tok) {
+		if (t.includes('.agentuity/') && frameRegex.test(t)) {
+			const parts = frameRegex.exec(t);
+			if (parts.length === 5) {
+				const filename = parts[2];
+				const sm = getSourceMap(filename+'.map');
+				if (sm) {
+					const lineno = parts[3];
+					const colno = parts[4];
+					const pos = sm.originalPositionFor({
+						line: +lineno,
+						column: +colno,
+					})
+					if (pos && pos.source) {
+						const startIndex = filename.indexOf('.agentuity/');
+						const offset = filename.includes('../node_modules/') ? 11 : 0;
+						const basedir = filename.substring(0, startIndex + offset);
+						const sourceOffset = pos.source.indexOf('src/');
+						const source = pos.source.substring(sourceOffset);
+						const newfile = __agentuity_join(basedir, source);
+						const newline = parts[1] + '(' + newfile + ':' + pos.line + ':' + pos.column + ')';
+						lines.push(newline);
+						continue;
+					}
+				}
+			}
+		}
+		lines.push(t);
+	}
+	return lines.join('\n');
+};
+})();
+`

internal/dev/dev.go

@@ -104,7 +104,7 @@ func FindAvailablePort(p project.ProjectContext, tryPort int) (int, error) {
 	return findAvailablePort()
 }
 
-func CreateRunProjectCmd(ctx context.Context, log logger.Logger, theproject project.ProjectContext, server *Server, dir string, orgId string, port int, writer io.Writer) (*exec.Cmd, error) {
+func CreateRunProjectCmd(ctx context.Context, log logger.Logger, theproject project.ProjectContext, server *Server, dir string, orgId string, port int, stdout io.Writer, stderr io.Writer) (*exec.Cmd, error) {
 	// set the vars
 	projectServerCmd := exec.CommandContext(ctx, theproject.Project.Development.Command, theproject.Project.Development.Args...)
 	projectServerCmd.Env = os.Environ()[:]
@@ -125,11 +125,23 @@ func CreateRunProjectCmd(ctx context.Context, log logger.Logger, theproject proj
 		projectServerCmd.Env = append(projectServerCmd.Env, "NODE_ENV=development")
 	}
 
+	// for nodejs, we need to enable source maps directly in the environment.
+	// for bun, we need to inject a shim helper to parse the source maps
+	if theproject.Project.Bundler.Runtime == "nodejs" {
+		nodeOptions := os.Getenv("NODE_OPTIONS")
+		if nodeOptions == "" {
+			nodeOptions = "--enable-source-maps"
+		} else {
+			nodeOptions = fmt.Sprintf("%s --enable-source-maps", nodeOptions)
+		}
+		projectServerCmd.Env = append(projectServerCmd.Env, nodeOptions)
+	}
+
 	projectServerCmd.Env = append(projectServerCmd.Env, fmt.Sprintf("AGENTUITY_CLOUD_PORT=%d", port))
 	projectServerCmd.Env = append(projectServerCmd.Env, fmt.Sprintf("PORT=%d", port))
 
-	projectServerCmd.Stdout = writer
-	projectServerCmd.Stderr = writer
+	projectServerCmd.Stdout = stdout
+	projectServerCmd.Stderr = stderr
 	projectServerCmd.Dir = dir
 
 	util.ProcessSetup(projectServerCmd)

internal/dev/pending_logger.go

@@ -10,8 +10,13 @@ import (
 	"github.com/agentuity/go-common/tui"
 )
 
+type pendingLog struct {
+	level logger.LogLevel
+	msg   string
+}
+
 type PendingLogger struct {
-	pending  []string
+	pending  []pendingLog
 	logLevel logger.LogLevel
 	logger   logger.Logger
 	mutex    sync.RWMutex
@@ -21,7 +26,7 @@ var _ logger.Logger = (*PendingLogger)(nil)
 
 func NewPendingLogger(logLevel logger.LogLevel) *PendingLogger {
 	return &PendingLogger{
-		pending:  make([]string, 0),
+		pending:  make([]pendingLog, 0),
 		logLevel: logLevel,
 	}
 }
@@ -30,7 +35,7 @@ func (l *PendingLogger) drain(ui *DevModeUI, logger logger.Logger) {
 	l.mutex.Lock()
 	defer l.mutex.Unlock()
 	for _, val := range l.pending {
-		ui.AddLog("%s", val)
+		ui.AddLog(val.level, "%s", val.msg)
 	}
 	l.logger = logger
 	l.pending = nil
@@ -62,7 +67,10 @@ func (l *PendingLogger) Trace(msg string, args ...interface{}) {
 		l.logger.Trace(msg, args...)
 		return
 	}
-	val := tui.Muted("[TRACE] " + fmt.Sprintf(msg, args...))
+	val := pendingLog{
+		level: logger.LevelTrace,
+		msg:   fmt.Sprintf(msg, args...),
+	}
 	l.pending = append(l.pending, val)
 }
 
@@ -77,7 +85,10 @@ func (l *PendingLogger) Debug(msg string, args ...interface{}) {
 		l.logger.Debug(msg, args...)
 		return
 	}
-	val := tui.Muted("[TRACE] " + fmt.Sprintf(msg, args...))
+	val := pendingLog{
+		level: logger.LevelDebug,
+		msg:   fmt.Sprintf(msg, args...),
+	}
 	l.pending = append(l.pending, val)
 }
 
@@ -92,7 +103,10 @@ func (l *PendingLogger) Info(msg string, args ...interface{}) {
 		l.logger.Info(msg, args...)
 		return
 	}
-	val := tui.Text("[INFO] " + fmt.Sprintf(msg, args...))
+	val := pendingLog{
+		level: logger.LevelInfo,
+		msg:   fmt.Sprintf(msg, args...),
+	}
 	l.pending = append(l.pending, val)
 }
 
@@ -107,7 +121,10 @@ func (l *PendingLogger) Warn(msg string, args ...interface{}) {
 		l.logger.Warn(msg, args...)
 		return
 	}
-	val := tui.Title("[WARN] " + fmt.Sprintf(msg, args...))
+	val := pendingLog{
+		level: logger.LevelWarn,
+		msg:   fmt.Sprintf(msg, args...),
+	}
 	l.pending = append(l.pending, val)
 }
 
@@ -122,7 +139,10 @@ func (l *PendingLogger) Error(msg string, args ...interface{}) {
 		l.logger.Error(msg, args...)
 		return
 	}
-	val := tui.Bold("[ERROR] " + fmt.Sprintf(msg, args...))
+	val := pendingLog{
+		level: logger.LevelError,
+		msg:   fmt.Sprintf(msg, args...),
+	}
 	l.pending = append(l.pending, val)
 }
 

internal/dev/server.go

@@ -547,8 +547,11 @@ func (s *Server) HealthCheck(devModeUrl string) error {
 	return fmt.Errorf("health check failed after %s", time.Since(started))
 }
 
-func (s *Server) Connect(ui *DevModeUI, tuiLogger logger.Logger) error {
+func (s *Server) Connect(ui *DevModeUI, tuiLogger logger.Logger, tuiLoggerErr logger.Logger) error {
 	s.logger = tuiLogger
+	if pl, ok := tuiLoggerErr.(*PendingLogger); ok {
+		pl.drain(ui, tuiLoggerErr)
+	}
 	if pl, ok := s.logger.(*PendingLogger); ok {
 		pl.drain(ui, s.logger)
 	}

internal/dev/tui.go

@@ -8,6 +8,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/agentuity/go-common/logger"
 	"github.com/agentuity/go-common/tui"
 	"github.com/charmbracelet/bubbles/key"
 	"github.com/charmbracelet/bubbles/list"
@@ -29,6 +30,10 @@ var (
 	runningColor      = lipgloss.AdaptiveColor{Light: "#00FF00", Dark: "#009900"}
 	pausedColor       = lipgloss.AdaptiveColor{Light: "#FFA500", Dark: "#FFA500"}
 	statusColor       = lipgloss.AdaptiveColor{Light: "#750075", Dark: "#FF5CFF"}
+	errorColor        = lipgloss.AdaptiveColor{Light: "#FF0000", Dark: "#EE0000"}
+	warningColor      = lipgloss.AdaptiveColor{Light: "#FFFF00", Dark: "#FFFF00"}
+	errorStyle        = lipgloss.NewStyle().Foreground(errorColor)
+	warningStyle      = lipgloss.NewStyle().Foreground(warningColor)
 	runningStyle      = lipgloss.NewStyle().Foreground(runningColor)
 	pausedStyle       = lipgloss.NewStyle().Foreground(pausedColor).AlignHorizontal(lipgloss.Center)
 	labelStyle        = lipgloss.NewStyle().Foreground(labelColor).Bold(true)
@@ -61,11 +66,25 @@ type spinnerStopMsg struct{}
 
 type logItem struct {
 	timestamp time.Time
+	severity  logger.LogLevel
 	message   string
 	raw       string
 }
 
-func (i logItem) Title() string       { return i.message }
+func (i logItem) Title() string {
+	switch i.severity {
+	case logger.LevelError:
+		return errorStyle.Render(i.message)
+	case logger.LevelDebug, logger.LevelTrace:
+		return tui.Muted(i.message)
+	case logger.LevelInfo:
+		return i.message
+	case logger.LevelWarn:
+		return warningStyle.Render(i.message)
+	default:
+		return i.message
+	}
+}
 func (i logItem) Description() string { return "" }
 func (i logItem) FilterValue() string { return i.message }
 
@@ -502,14 +521,30 @@ func (d *DevModeUI) Start() {
 }
 
 // Add a log message to the log list
-func (d *DevModeUI) AddLog(log string, args ...any) {
+func (d *DevModeUI) AddLog(severity logger.LogLevel, log string, args ...any) {
 	if !d.enabled {
 		fmt.Println(fmt.Sprintf(log, args...))
 		return
 	}
 	raw := fmt.Sprintf(log, args...)
 	d.program.Send(addLogMsg{
 		timestamp: time.Now(),
+		severity:  severity,
+		raw:       raw,
+		message:   strings.ReplaceAll(ansiColorStripper.ReplaceAllString(raw, ""), "\n", " "),
+	})
+}
+
+// Add an error log message to the log list
+func (d *DevModeUI) AddErrorLog(log string, args ...any) {
+	if !d.enabled {
+		fmt.Println(errorStyle.Render(fmt.Sprintf(log, args...)))
+		return
+	}
+	raw := fmt.Sprintf(log, args...)
+	d.program.Send(addLogMsg{
+		timestamp: time.Now(),
+		severity:  logger.LevelError,
 		raw:       raw,
 		message:   strings.ReplaceAll(ansiColorStripper.ReplaceAllString(raw, ""), "\n", " "),
 	})