Skip to content

Commit d15ce9b

Browse files
committed
feat(logging): add app debug logging throughout TUI components
Add new appDebug logging function and integrate it across TUI components to track initialization and workflow execution. Pin @opentui/core version to exact 0.1.60 to prevent potential version mismatches. The logging helps diagnose startup issues and track application flow, particularly during critical paths like workflow execution and component initialization. The version pinning ensures consistent behavior across environments.
1 parent 7d99ee6 commit d15ce9b

7 files changed

Lines changed: 140 additions & 11 deletions

File tree

bun.lock

Lines changed: 1 addition & 1 deletion
Some generated files are not rendered by default. Learn more about customizing how changed files appear on GitHub.

package.json

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -69,7 +69,7 @@
6969
"dependencies": {
7070
"@clack/prompts": "^0.11.0",
7171
"@modelcontextprotocol/sdk": "^1.0.0",
72-
"@opentui/core": "^0.1.60",
72+
"@opentui/core": "0.1.60",
7373
"@opentui/solid": "^0.1.60",
7474
"chalk": "^5.6.2",
7575
"commander": "^14.0.1",

src/cli/tui/app-shell.tsx

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ import { Workflow } from "@tui/routes/workflow"
1919
import { Onboard } from "@tui/routes/onboard"
2020
import { homedir } from "os"
2121
import { WorkflowEventBus, OnboardingService } from "../../workflows/events/index.js"
22-
import { debug, setDebugLogFile } from "../../shared/logging/logger.js"
22+
import { debug, setDebugLogFile, appDebug } from "../../shared/logging/logger.js"
2323
import { MonitoringCleanup } from "../../agents/monitoring/index.js"
2424
import path from "path"
2525
import { createRequire } from "node:module"
@@ -104,16 +104,19 @@ async function copyToSystemClipboard(text: string): Promise<void> {
104104
}
105105

106106
export function App(props: { initialToast?: InitialToast }) {
107+
appDebug('[AppShell] App component initializing')
107108
const dimensions = useTerminalDimensions()
108109
const themeCtx = useTheme()
109110
const session = useSession()
110111
const updateNotifier = useUpdateNotifier()
111112
const renderer = useRenderer()
112113
const toast = useToast()
113114
const kv = useKV()
115+
appDebug('[AppShell] Hooks initialized')
114116

115117
// Global error handler - any part of the app can emit 'app:error' to show a toast
116118
const handleAppError = (data: { message: string; duration?: number }) => {
119+
appDebug('[AppShell] App error received: %s', data.message)
117120
toast.show({
118121
variant: "error",
119122
message: data.message,
@@ -143,15 +146,18 @@ export function App(props: { initialToast?: InitialToast }) {
143146
}
144147

145148
const handleStartWorkflow = async () => {
149+
appDebug('[AppShell] handleStartWorkflow called')
146150
const cwd = process.env.CODEMACHINE_CWD || process.cwd()
147151
const cmRoot = path.join(cwd, '.codemachine')
152+
appDebug('[AppShell] cwd=%s, cmRoot=%s', cwd, cmRoot)
148153

149154
// Initialize debug log file early (before onboarding) so all logs are captured
150155
const rawLogLevel = (process.env.LOG_LEVEL || '').trim().toLowerCase()
151156
const debugFlag = (process.env.DEBUG || '').trim().toLowerCase()
152157
const debugEnabled = rawLogLevel === 'debug' || (debugFlag !== '' && debugFlag !== '0' && debugFlag !== 'false')
153158
if (debugEnabled) {
154159
const debugLogPath = path.join(cwd, '.codemachine', 'logs', 'workflow-debug.log')
160+
appDebug('[AppShell] Switching to workflow debug log: %s', debugLogPath)
155161
setDebugLogFile(debugLogPath)
156162
}
157163

@@ -221,34 +227,41 @@ export function App(props: { initialToast?: InitialToast }) {
221227
}
222228
} catch (error) {
223229
// If template loading fails, proceed to workflow anyway
230+
appDebug('[AppShell] Failed to check tracks/conditions: %s', error)
224231
console.error("Failed to check tracks/conditions:", error)
225232
}
226233

227234
// No tracks/conditions or already selected - start workflow directly
235+
appDebug('[AppShell] Starting workflow execution directly')
228236
startWorkflowExecution()
229237
}
230238

231239
const startWorkflowExecution = () => {
240+
appDebug('[AppShell] startWorkflowExecution called')
232241
const eventBus = new WorkflowEventBus()
233242
setWorkflowEventBus(eventBus)
234243
// @ts-expect-error - global export for workflow connection
235244
globalThis.__workflowEventBus = eventBus
236245

237246
const cwd = process.env.CODEMACHINE_CWD || process.cwd()
238247
const specPath = path.join(cwd, '.codemachine', 'inputs', 'specifications.md')
248+
appDebug('[AppShell] specPath=%s', specPath)
239249

240250
pendingWorkflowStart = () => {
251+
appDebug('[AppShell] Importing and running workflow')
241252
import("../../workflows/run.js").then(({ runWorkflow }) => {
242253
runWorkflow({ cwd, specificationPath: specPath }).catch((error) => {
243254
// Emit error event to show toast with actual error message
244255
const errorMsg = error instanceof Error ? error.message : String(error)
256+
appDebug('[AppShell] Workflow error: %s', errorMsg)
245257
;(process as NodeJS.EventEmitter).emit('app:error', { message: errorMsg })
246258
})
247259
})
248260
}
249261

250262
currentView = "workflow"
251263
setView("workflow")
264+
appDebug('[AppShell] View set to workflow')
252265
}
253266

254267
const handleOnboardComplete = async (result: { projectName?: string; trackId?: string; conditions?: string[]; controllerAgentId?: string }) => {

src/cli/tui/app.tsx

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ import { initTUILogger, closeTUILogger } from "@tui/shared/utils/tui-logger"
1818
import { getSavedTheme, getTerminalBackgroundColor } from "./utils"
1919
import { App, currentView } from "./app-shell"
2020
import { ErrorComponent } from "./components/error-boundary"
21+
import { appDebug } from "../../shared/logging/logger.js"
2122

2223
export type InitialToast = {
2324
variant: "success" | "error" | "info" | "warning"
@@ -57,27 +58,37 @@ export async function startTUI(
5758
knownMode?: "dark" | "light",
5859
initialToast?: InitialToast
5960
): Promise<void> {
61+
appDebug('[TUI] startTUI called, skipBackgroundDetection=%s', skipBackgroundDetection)
62+
6063
// Priority: 1. Saved theme from KV, 2. Known mode, 3. Auto-detect
64+
appDebug('[TUI] Getting saved theme')
6165
const savedTheme = await getSavedTheme()
66+
appDebug('[TUI] savedTheme=%s', savedTheme)
67+
6268
const mode = savedTheme
6369
?? (skipBackgroundDetection && knownMode ? knownMode : null)
6470
?? await getTerminalBackgroundColor()
71+
appDebug('[TUI] Resolved mode=%s', mode)
6572

6673
// Wait for stdin to settle after background detection
6774
if (!skipBackgroundDetection) {
75+
appDebug('[TUI] Waiting for stdin to settle')
6876
await new Promise((r) => setTimeout(r, 100))
6977
}
7078

7179
// Clear terminal before OpenTUI takes over
7280
if (process.stdout.isTTY) {
81+
appDebug('[TUI] Clearing terminal')
7382
process.stdout.write('\x1b[2J\x1b[H\x1b[?25h')
7483
}
7584

85+
appDebug('[TUI] Starting OpenTUI render')
7686
return new Promise<void>((resolve) => {
7787
const vignetteEffect = new VignetteEffect(0.35)
7888

7989
render(
8090
() => <Root mode={mode} initialToast={initialToast} onExit={() => {
91+
appDebug('[TUI] onExit called, closing TUI')
8192
closeTUILogger()
8293
if (process.stdout.isTTY) {
8394
process.stdout.write('\x1b[2J\x1b[H\x1b[?25h')
@@ -103,7 +114,9 @@ export async function startTUI(
103114
}
104115
)
105116

117+
appDebug('[TUI] Render started, initializing TUI logger in 200ms')
106118
setTimeout(() => {
119+
appDebug('[TUI] Initializing TUI logger')
107120
initTUILogger()
108121
}, 200)
109122
})

src/cli/tui/launcher.ts

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -16,15 +16,21 @@
1616
* to ensure the plugin is registered before any JSX files are parsed.
1717
*/
1818

19+
import { appDebug } from '../../shared/logging/logger.js';
20+
1921
// Only load preload in dev mode (when running from source)
2022
// In production binaries, JSX is pre-transformed during build
2123
const isDev = import.meta.url.includes('/src/')
24+
appDebug('[Launcher] isDev=%s', isDev);
2225
if (isDev) {
26+
appDebug('[Launcher] Loading OpenTUI preload');
2327
await import("@opentui/solid/preload")
2428
}
2529

2630
// Dynamic import ensures app.js is loaded AFTER preload is registered (in dev)
2731
export async function startTUI() {
32+
appDebug('[Launcher] Importing TUI app module');
2833
const app = await import("./app.js");
34+
appDebug('[Launcher] Starting TUI app');
2935
return app.startTUI();
3036
}

src/runtime/cli-setup.ts

Lines changed: 74 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,30 +1,54 @@
1+
// EARLY LOGGING SETUP - Initialize before anything else
2+
import * as path from 'node:path';
3+
import { setAppLogFile, appDebug } from '../shared/logging/logger.js';
4+
5+
const earlyCwd = process.env.CODEMACHINE_CWD || process.cwd();
6+
const earlyLogLevel = (process.env.LOG_LEVEL || '').trim().toLowerCase();
7+
const earlyDebugFlag = (process.env.DEBUG || '').trim().toLowerCase();
8+
const earlyDebugEnabled = earlyLogLevel === 'debug' || (earlyDebugFlag !== '' && earlyDebugFlag !== '0' && earlyDebugFlag !== 'false');
9+
if (earlyDebugEnabled) {
10+
const appDebugLogPath = path.join(earlyCwd, '.codemachine', 'logs', 'app-debug.log');
11+
setAppLogFile(appDebugLogPath);
12+
}
13+
appDebug('[Boot] CLI module loading started');
14+
115
// ENSURE EMBEDDED RESOURCES EARLY (BEFORE IMPORTS)
216
// This must run before any modules that might resolve the package root
17+
appDebug('[Boot] Importing embed module');
318
import { ensure as ensureResources } from '../shared/runtime/embed.js';
419

20+
appDebug('[Boot] Ensuring embedded resources');
521
const embeddedRoot = await ensureResources();
22+
appDebug('[Boot] embeddedRoot=%s', embeddedRoot);
623

724
if (!embeddedRoot && !process.env.CODEMACHINE_INSTALL_DIR) {
825
// Fallback to normal resolution if not embedded
26+
appDebug('[Boot] Resolving package root (fallback)');
927
const { resolvePackageRoot } = await import('../shared/runtime/root.js');
1028
try {
1129
const packageRoot = resolvePackageRoot(import.meta.url, 'cli-setup');
1230
process.env.CODEMACHINE_INSTALL_DIR = packageRoot;
13-
} catch {
31+
appDebug('[Boot] CODEMACHINE_INSTALL_DIR=%s', packageRoot);
32+
} catch (err) {
33+
appDebug('[Boot] Failed to resolve package root: %s', err);
1434
// Continue without setting
1535
}
1636
}
1737

1838
// IMMEDIATE SPLASH - Only show for main TUI session
1939
// Skip splash for: subcommands, help flags, or version flags
40+
appDebug('[Boot] Checking splash screen conditions');
2041
const args = process.argv.slice(2);
42+
appDebug('[Boot] args=%o', args);
2143
const hasSubcommand = args.length > 0 && !args[0].startsWith('-');
2244
const hasHelpOrVersion = args.some(arg =>
2345
arg === '--help' || arg === '-h' || arg === '--version' || arg === '-V'
2446
);
2547
const shouldSkipSplash = hasSubcommand || hasHelpOrVersion;
48+
appDebug('[Boot] hasSubcommand=%s, hasHelpOrVersion=%s, shouldSkipSplash=%s', hasSubcommand, hasHelpOrVersion, shouldSkipSplash);
2649

2750
if (process.stdout.isTTY && !shouldSkipSplash) {
51+
appDebug('[Boot] Showing splash screen');
2852
const { rows = 24, columns = 80 } = process.stdout;
2953
const centerY = Math.floor(rows / 2);
3054
const centerX = Math.floor(columns / 2);
@@ -33,12 +57,14 @@ if (process.stdout.isTTY && !shouldSkipSplash) {
3357
process.stdout.write('\x1b[38;2;224;230;240mCode\x1b[1mMachine\x1b[0m');
3458
process.stdout.write(`\x1b[${centerY + 1};${centerX - 6}H`);
3559
process.stdout.write('\x1b[38;2;0;217;255m━━━━━━━━━━━━\x1b[0m');
60+
appDebug('[Boot] Splash screen displayed');
3661
}
3762

63+
appDebug('[Boot] Importing remaining modules');
3864
import { Command } from 'commander';
3965
import { existsSync, realpathSync } from 'node:fs';
4066
import { fileURLToPath } from 'node:url';
41-
import * as path from 'node:path';
67+
appDebug('[Boot] Imports complete');
4268

4369
const DEFAULT_SPEC_PATH = '.codemachine/inputs/specifications.md';
4470

@@ -51,6 +77,7 @@ async function initializeInBackground(cwd: string): Promise<void> {
5177

5278
// Only bootstrap if .codemachine doesn't exist
5379
if (!existsSync(cmRoot)) {
80+
appDebug('[Init] Bootstrapping workspace (first run)');
5481
// Lazy load bootstrap utilities (only on first run)
5582
const { bootstrapWorkspace } = await import('./services/workspace/index.js');
5683
const { resolvePackageRoot } = await import('../shared/runtime/root.js');
@@ -60,23 +87,31 @@ async function initializeInBackground(cwd: string): Promise<void> {
6087
const defaultTemplate = path.join(templatesDir, 'codemachine.workflow.js');
6188

6289
await bootstrapWorkspace({ cwd, templatePath: defaultTemplate });
90+
appDebug('[Init] Workspace bootstrapped');
6391
}
6492

6593
// Lazy load and initialize engine registry
94+
appDebug('[Init] Loading engine registry');
6695
const { registry } = await import('../infra/engines/index.js');
6796
const engines = registry.getAll();
6897

6998
// Sync engine configs in background
99+
appDebug('[Init] Syncing %d engine configs', engines.length);
70100
for (const engine of engines) {
71101
if (engine.syncConfig) {
72102
await engine.syncConfig();
73103
}
74104
}
105+
appDebug('[Init] Background initialization complete');
75106
}
76107

77108
export async function runCodemachineCli(argv: string[] = process.argv): Promise<void> {
109+
appDebug('[CLI] runCodemachineCli started');
110+
78111
// Import version from auto-generated version file (works in compiled binaries)
112+
appDebug('[CLI] Importing version');
79113
const { VERSION } = await import('./version.js');
114+
appDebug('[CLI] VERSION=%s', VERSION);
80115

81116
const program = new Command()
82117
.name('codemachine')
@@ -91,53 +126,84 @@ export async function runCodemachineCli(argv: string[] = process.argv): Promise<
91126

92127
// Start background initialization (non-blocking, fire-and-forget)
93128
// This runs while TUI is visible and user is reading/thinking
129+
appDebug('[CLI] Starting background initialization');
94130
initializeInBackground(cwd).catch(err => {
131+
appDebug('[CLI] Background init error: %s', err);
95132
console.error('[Background Init Error]', err);
96133
});
97134

98135
// Launch TUI immediately - don't wait for background init
99136
// Import via launcher to scope SolidJS transform to TUI only
137+
appDebug('[CLI] Launching TUI');
100138
const { startTUI } = await import('../cli/tui/launcher.js');
101139
await startTUI();
140+
appDebug('[CLI] TUI exited');
102141
});
103142

104143
// Lazy load CLI commands only if user uses subcommands
105144
if (argv.length > 2 && !argv[2].startsWith('-')) {
145+
appDebug('[CLI] Loading subcommands');
106146
const { registerCli } = await import('../cli/index.js');
107147
await registerCli(program);
148+
appDebug('[CLI] Subcommands registered');
108149
}
109150

151+
appDebug('[CLI] Parsing command line');
110152
await program.parseAsync(argv);
153+
appDebug('[CLI] Command line parsed');
111154
}
112155

156+
appDebug('[Boot] Checking shouldRunCli');
113157
const shouldRunCli = (() => {
114158
const entry = process.argv[1];
115-
if (!entry) return false;
159+
appDebug('[Boot] entry=%s', entry);
160+
if (!entry) {
161+
appDebug('[Boot] No entry, returning false');
162+
return false;
163+
}
116164

117165
// For compiled binaries, Bun.main will be the binary itself
118166
if (typeof Bun !== 'undefined' && Bun.main) {
167+
appDebug('[Boot] Checking Bun.main');
119168
try {
120169
const mainPath = fileURLToPath(Bun.main);
121170
const modulePath = fileURLToPath(import.meta.url);
122-
if (mainPath === modulePath) return true;
123-
} catch {
171+
appDebug('[Boot] mainPath=%s, modulePath=%s', mainPath, modulePath);
172+
if (mainPath === modulePath) {
173+
appDebug('[Boot] Bun.main matches, returning true');
174+
return true;
175+
}
176+
} catch (err) {
177+
appDebug('[Boot] Bun.main check failed: %s', err);
124178
// Continue to other checks
125179
}
126180
}
127181

128182
try {
129183
const resolvedEntry = realpathSync(entry);
130184
const modulePath = realpathSync(fileURLToPath(import.meta.url));
131-
return resolvedEntry === modulePath;
132-
} catch {
185+
appDebug('[Boot] resolvedEntry=%s, modulePath=%s', resolvedEntry, modulePath);
186+
const matches = resolvedEntry === modulePath;
187+
appDebug('[Boot] realpathSync matches=%s', matches);
188+
return matches;
189+
} catch (err) {
190+
appDebug('[Boot] realpathSync failed: %s, using fallback', err);
133191
// Fallback: if entry contains 'index' or 'codemachine', run CLI
134-
return entry.includes('index') || entry.includes('codemachine');
192+
const fallback = entry.includes('index') || entry.includes('codemachine');
193+
appDebug('[Boot] fallback result=%s', fallback);
194+
return fallback;
135195
}
136196
})();
137197

198+
appDebug('[Boot] shouldRunCli=%s', shouldRunCli);
199+
138200
if (shouldRunCli) {
201+
appDebug('[Boot] Calling runCodemachineCli()');
139202
runCodemachineCli().catch((error) => {
203+
appDebug('[Boot] runCodemachineCli error: %s', error);
140204
console.error(error);
141205
process.exitCode = 1;
142206
});
207+
} else {
208+
appDebug('[Boot] CLI not run (shouldRunCli=false)');
143209
}

0 commit comments

Comments
 (0)