feat(server): migrate all logging to pino

- Add pino with pino-pretty for structured logging
- Create root logger in index.ts with child loggers per module
- Support log level via PASEO_LOG env var and config.json
- Support log format (pretty/json) via PASEO_LOG_FORMAT and config.json
- Replace all console.* in runtime code with appropriate log levels
- Scripts use process.stdout/stderr for output
- Error logging uses correct pattern: logger.error({ err }, msg)
This commit is contained in:
Mohamed Boudra
2026-01-15 17:16:01 +07:00
parent ef853914d5
commit b8f056060f
48 changed files with 1275 additions and 887 deletions
+237 -1
View File
@@ -6335,6 +6335,12 @@
"resolved": "packages/website", "resolved": "packages/website",
"link": true "link": true
}, },
"node_modules/@pinojs/redact": {
"version": "0.4.0",
"resolved": "https://registry.npmjs.org/@pinojs/redact/-/redact-0.4.0.tgz",
"integrity": "sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==",
"license": "MIT"
},
"node_modules/@pkgjs/parseargs": { "node_modules/@pkgjs/parseargs": {
"version": "0.11.0", "version": "0.11.0",
"resolved": "https://registry.npmjs.org/@pkgjs/parseargs/-/parseargs-0.11.0.tgz", "resolved": "https://registry.npmjs.org/@pkgjs/parseargs/-/parseargs-0.11.0.tgz",
@@ -10053,6 +10059,15 @@
"node": ">= 4.0.0" "node": ">= 4.0.0"
} }
}, },
"node_modules/atomic-sleep": {
"version": "1.0.0",
"resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz",
"integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==",
"license": "MIT",
"engines": {
"node": ">=8.0.0"
}
},
"node_modules/available-typed-arrays": { "node_modules/available-typed-arrays": {
"version": "1.0.7", "version": "1.0.7",
"resolved": "https://registry.npmjs.org/available-typed-arrays/-/available-typed-arrays-1.0.7.tgz", "resolved": "https://registry.npmjs.org/available-typed-arrays/-/available-typed-arrays-1.0.7.tgz",
@@ -11069,6 +11084,12 @@
"simple-swizzle": "^0.2.2" "simple-swizzle": "^0.2.2"
} }
}, },
"node_modules/colorette": {
"version": "2.0.20",
"resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz",
"integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==",
"license": "MIT"
},
"node_modules/colorjs.io": { "node_modules/colorjs.io": {
"version": "0.6.0-alpha.1", "version": "0.6.0-alpha.1",
"resolved": "https://registry.npmjs.org/colorjs.io/-/colorjs.io-0.6.0-alpha.1.tgz", "resolved": "https://registry.npmjs.org/colorjs.io/-/colorjs.io-0.6.0-alpha.1.tgz",
@@ -11487,7 +11508,6 @@
"version": "4.6.3", "version": "4.6.3",
"resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz", "resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz",
"integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==", "integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==",
"dev": true,
"license": "MIT", "license": "MIT",
"engines": { "engines": {
"node": "*" "node": "*"
@@ -12390,6 +12410,15 @@
"node": ">=0.10.0" "node": ">=0.10.0"
} }
}, },
"node_modules/end-of-stream": {
"version": "1.4.5",
"resolved": "https://registry.npmjs.org/end-of-stream/-/end-of-stream-1.4.5.tgz",
"integrity": "sha512-ooEGc6HP26xXq/N+GCGOT0JKCLDGrq2bQUZrQ7gyrJiZANJ/8YDTxTpQBXGMn+WbIQXNVpyWymm7KYVICQnyOg==",
"license": "MIT",
"dependencies": {
"once": "^1.4.0"
}
},
"node_modules/enhanced-resolve": { "node_modules/enhanced-resolve": {
"version": "5.18.4", "version": "5.18.4",
"resolved": "https://registry.npmjs.org/enhanced-resolve/-/enhanced-resolve-5.18.4.tgz", "resolved": "https://registry.npmjs.org/enhanced-resolve/-/enhanced-resolve-5.18.4.tgz",
@@ -14207,6 +14236,12 @@
"integrity": "sha512-LmDxfWXwcTArk8fUEnOfSZpHOJ6zOMUJKOtFLFqJLoKJetuQG874Uc7/Kki7zFLzYybmZhp1M7+98pfMqeX8yA==", "integrity": "sha512-LmDxfWXwcTArk8fUEnOfSZpHOJ6zOMUJKOtFLFqJLoKJetuQG874Uc7/Kki7zFLzYybmZhp1M7+98pfMqeX8yA==",
"license": "MIT" "license": "MIT"
}, },
"node_modules/fast-copy": {
"version": "4.0.2",
"resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.0.2.tgz",
"integrity": "sha512-ybA6PDXIXOXivLJK/z9e+Otk7ve13I4ckBvGO5I2RRmBU1gMHLVDJYEuJYhGwez7YNlYji2M2DvVU+a9mSFDlw==",
"license": "MIT"
},
"node_modules/fast-deep-equal": { "node_modules/fast-deep-equal": {
"version": "3.1.3", "version": "3.1.3",
"resolved": "https://registry.npmjs.org/fast-deep-equal/-/fast-deep-equal-3.1.3.tgz", "resolved": "https://registry.npmjs.org/fast-deep-equal/-/fast-deep-equal-3.1.3.tgz",
@@ -14263,6 +14298,12 @@
"dev": true, "dev": true,
"license": "MIT" "license": "MIT"
}, },
"node_modules/fast-safe-stringify": {
"version": "2.1.1",
"resolved": "https://registry.npmjs.org/fast-safe-stringify/-/fast-safe-stringify-2.1.1.tgz",
"integrity": "sha512-W+KJc2dmILlPplD/H4K9l9LcAHAfPtP6BY84uVLXQ6Evcz9Lcg33Y2z1IVblT6xdY54PXYVHEv+0Wpq8Io6zkA==",
"license": "MIT"
},
"node_modules/fast-uri": { "node_modules/fast-uri": {
"version": "3.1.0", "version": "3.1.0",
"resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.0.tgz", "resolved": "https://registry.npmjs.org/fast-uri/-/fast-uri-3.1.0.tgz",
@@ -15188,6 +15229,12 @@
"node": ">= 0.4" "node": ">= 0.4"
} }
}, },
"node_modules/help-me": {
"version": "5.0.0",
"resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz",
"integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==",
"license": "MIT"
},
"node_modules/hermes-estree": { "node_modules/hermes-estree": {
"version": "0.29.1", "version": "0.29.1",
"resolved": "https://registry.npmjs.org/hermes-estree/-/hermes-estree-0.29.1.tgz", "resolved": "https://registry.npmjs.org/hermes-estree/-/hermes-estree-0.29.1.tgz",
@@ -16387,6 +16434,15 @@
"dev": true, "dev": true,
"license": "MIT" "license": "MIT"
}, },
"node_modules/joycon": {
"version": "3.1.1",
"resolved": "https://registry.npmjs.org/joycon/-/joycon-3.1.1.tgz",
"integrity": "sha512-34wB/Y7MW7bzjKRjUKTa46I2Z7eV62Rkhva+KkopW7Qvv/OSWBqvkSY7vusOPrNuZcUG3tApvdVgNB8POj3SPw==",
"license": "MIT",
"engines": {
"node": ">=10"
}
},
"node_modules/js-tokens": { "node_modules/js-tokens": {
"version": "4.0.0", "version": "4.0.0",
"resolved": "https://registry.npmjs.org/js-tokens/-/js-tokens-4.0.0.tgz", "resolved": "https://registry.npmjs.org/js-tokens/-/js-tokens-4.0.0.tgz",
@@ -18299,6 +18355,15 @@
"url": "https://github.com/sponsors/ljharb" "url": "https://github.com/sponsors/ljharb"
} }
}, },
"node_modules/on-exit-leak-free": {
"version": "2.1.2",
"resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz",
"integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==",
"license": "MIT",
"engines": {
"node": ">=14.0.0"
}
},
"node_modules/on-finished": { "node_modules/on-finished": {
"version": "2.4.1", "version": "2.4.1",
"resolved": "https://registry.npmjs.org/on-finished/-/on-finished-2.4.1.tgz", "resolved": "https://registry.npmjs.org/on-finished/-/on-finished-2.4.1.tgz",
@@ -18818,6 +18883,79 @@
"url": "https://github.com/sponsors/jonschlinkert" "url": "https://github.com/sponsors/jonschlinkert"
} }
}, },
"node_modules/pino": {
"version": "10.2.0",
"resolved": "https://registry.npmjs.org/pino/-/pino-10.2.0.tgz",
"integrity": "sha512-NFnZqUliT+OHkRXVSf8vdOr13N1wv31hRryVjqbreVh/SDCNaI6mnRDDq89HVRCbem1SAl7yj04OANeqP0nT6A==",
"license": "MIT",
"dependencies": {
"@pinojs/redact": "^0.4.0",
"atomic-sleep": "^1.0.0",
"on-exit-leak-free": "^2.1.0",
"pino-abstract-transport": "^3.0.0",
"pino-std-serializers": "^7.0.0",
"process-warning": "^5.0.0",
"quick-format-unescaped": "^4.0.3",
"real-require": "^0.2.0",
"safe-stable-stringify": "^2.3.1",
"sonic-boom": "^4.0.1",
"thread-stream": "^4.0.0"
},
"bin": {
"pino": "bin.js"
}
},
"node_modules/pino-abstract-transport": {
"version": "3.0.0",
"resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz",
"integrity": "sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==",
"license": "MIT",
"dependencies": {
"split2": "^4.0.0"
}
},
"node_modules/pino-pretty": {
"version": "13.1.3",
"resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.1.3.tgz",
"integrity": "sha512-ttXRkkOz6WWC95KeY9+xxWL6AtImwbyMHrL1mSwqwW9u+vLp/WIElvHvCSDg0xO/Dzrggz1zv3rN5ovTRVowKg==",
"license": "MIT",
"dependencies": {
"colorette": "^2.0.7",
"dateformat": "^4.6.3",
"fast-copy": "^4.0.0",
"fast-safe-stringify": "^2.1.1",
"help-me": "^5.0.0",
"joycon": "^3.1.1",
"minimist": "^1.2.6",
"on-exit-leak-free": "^2.1.0",
"pino-abstract-transport": "^3.0.0",
"pump": "^3.0.0",
"secure-json-parse": "^4.0.0",
"sonic-boom": "^4.0.1",
"strip-json-comments": "^5.0.2"
},
"bin": {
"pino-pretty": "bin.js"
}
},
"node_modules/pino-pretty/node_modules/strip-json-comments": {
"version": "5.0.3",
"resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-5.0.3.tgz",
"integrity": "sha512-1tB5mhVo7U+ETBKNf92xT4hrQa3pm0MZ0PQvuDnWgAAGHDsfp4lPSpiS6psrSiet87wyGPh9ft6wmhOMQ0hDiw==",
"license": "MIT",
"engines": {
"node": ">=14.16"
},
"funding": {
"url": "https://github.com/sponsors/sindresorhus"
}
},
"node_modules/pino-std-serializers": {
"version": "7.1.0",
"resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz",
"integrity": "sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==",
"license": "MIT"
},
"node_modules/pirates": { "node_modules/pirates": {
"version": "4.0.7", "version": "4.0.7",
"resolved": "https://registry.npmjs.org/pirates/-/pirates-4.0.7.tgz", "resolved": "https://registry.npmjs.org/pirates/-/pirates-4.0.7.tgz",
@@ -19080,6 +19218,22 @@
"node": "^14.17.0 || ^16.13.0 || >=18.0.0" "node": "^14.17.0 || ^16.13.0 || >=18.0.0"
} }
}, },
"node_modules/process-warning": {
"version": "5.0.0",
"resolved": "https://registry.npmjs.org/process-warning/-/process-warning-5.0.0.tgz",
"integrity": "sha512-a39t9ApHNx2L4+HBnQKqxxHNs1r7KF+Intd8Q/g1bUh6q0WIp9voPXJ/x0j+ZL45KF1pJd9+q2jLIRMfvEshkA==",
"funding": [
{
"type": "github",
"url": "https://github.com/sponsors/fastify"
},
{
"type": "opencollective",
"url": "https://opencollective.com/fastify"
}
],
"license": "MIT"
},
"node_modules/progress": { "node_modules/progress": {
"version": "2.0.3", "version": "2.0.3",
"resolved": "https://registry.npmjs.org/progress/-/progress-2.0.3.tgz", "resolved": "https://registry.npmjs.org/progress/-/progress-2.0.3.tgz",
@@ -19162,6 +19316,16 @@
"node": ">= 0.10" "node": ">= 0.10"
} }
}, },
"node_modules/pump": {
"version": "3.0.3",
"resolved": "https://registry.npmjs.org/pump/-/pump-3.0.3.tgz",
"integrity": "sha512-todwxLMY7/heScKmntwQG8CXVkWUOdYxIvY2s0VWAAMh/nd8SoYiRaKjlr7+iCs984f2P8zvrfWcDDYVb73NfA==",
"license": "MIT",
"dependencies": {
"end-of-stream": "^1.1.0",
"once": "^1.3.1"
}
},
"node_modules/punycode": { "node_modules/punycode": {
"version": "2.3.1", "version": "2.3.1",
"resolved": "https://registry.npmjs.org/punycode/-/punycode-2.3.1.tgz", "resolved": "https://registry.npmjs.org/punycode/-/punycode-2.3.1.tgz",
@@ -19243,6 +19407,12 @@
], ],
"license": "MIT" "license": "MIT"
}, },
"node_modules/quick-format-unescaped": {
"version": "4.0.4",
"resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz",
"integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==",
"license": "MIT"
},
"node_modules/range-parser": { "node_modules/range-parser": {
"version": "1.2.1", "version": "1.2.1",
"resolved": "https://registry.npmjs.org/range-parser/-/range-parser-1.2.1.tgz", "resolved": "https://registry.npmjs.org/range-parser/-/range-parser-1.2.1.tgz",
@@ -19917,6 +20087,15 @@
"url": "https://github.com/sponsors/jonschlinkert" "url": "https://github.com/sponsors/jonschlinkert"
} }
}, },
"node_modules/real-require": {
"version": "0.2.0",
"resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz",
"integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==",
"license": "MIT",
"engines": {
"node": ">= 12.13.0"
}
},
"node_modules/recast": { "node_modules/recast": {
"version": "0.23.11", "version": "0.23.11",
"resolved": "https://registry.npmjs.org/recast/-/recast-0.23.11.tgz", "resolved": "https://registry.npmjs.org/recast/-/recast-0.23.11.tgz",
@@ -20447,6 +20626,15 @@
"url": "https://github.com/sponsors/ljharb" "url": "https://github.com/sponsors/ljharb"
} }
}, },
"node_modules/safe-stable-stringify": {
"version": "2.5.0",
"resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz",
"integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==",
"license": "MIT",
"engines": {
"node": ">=10"
}
},
"node_modules/safer-buffer": { "node_modules/safer-buffer": {
"version": "2.1.2", "version": "2.1.2",
"resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz",
@@ -20465,6 +20653,22 @@
"integrity": "sha512-NlHwttCI/l5gCPR3D1nNXtWABUmBwvZpEQiD4IXSbIDq8BzLIK/7Ir5gTFSGZDUu37K5cMNp0hFtzO38sC7gWA==", "integrity": "sha512-NlHwttCI/l5gCPR3D1nNXtWABUmBwvZpEQiD4IXSbIDq8BzLIK/7Ir5gTFSGZDUu37K5cMNp0hFtzO38sC7gWA==",
"license": "MIT" "license": "MIT"
}, },
"node_modules/secure-json-parse": {
"version": "4.1.0",
"resolved": "https://registry.npmjs.org/secure-json-parse/-/secure-json-parse-4.1.0.tgz",
"integrity": "sha512-l4KnYfEyqYJxDwlNVyRfO2E4NTHfMKAWdUuA8J0yve2Dz/E/PdBepY03RvyJpssIpRFwJoCD55wA+mEDs6ByWA==",
"funding": [
{
"type": "github",
"url": "https://github.com/sponsors/fastify"
},
{
"type": "opencollective",
"url": "https://opencollective.com/fastify"
}
],
"license": "BSD-3-Clause"
},
"node_modules/semver": { "node_modules/semver": {
"version": "6.3.1", "version": "6.3.1",
"resolved": "https://registry.npmjs.org/semver/-/semver-6.3.1.tgz", "resolved": "https://registry.npmjs.org/semver/-/semver-6.3.1.tgz",
@@ -21281,6 +21485,15 @@
"node": ">=8.0.0" "node": ">=8.0.0"
} }
}, },
"node_modules/sonic-boom": {
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.0.tgz",
"integrity": "sha512-INb7TM37/mAcsGmc9hyyI6+QR3rR1zVRu36B0NeGXKnOOLiZOfER5SA+N7X7k3yUYRzLWafduTDvJAfDswwEww==",
"license": "MIT",
"dependencies": {
"atomic-sleep": "^1.0.0"
}
},
"node_modules/source-map": { "node_modules/source-map": {
"version": "0.5.7", "version": "0.5.7",
"resolved": "https://registry.npmjs.org/source-map/-/source-map-0.5.7.tgz", "resolved": "https://registry.npmjs.org/source-map/-/source-map-0.5.7.tgz",
@@ -21340,6 +21553,15 @@
"node": ">=6" "node": ">=6"
} }
}, },
"node_modules/split2": {
"version": "4.2.0",
"resolved": "https://registry.npmjs.org/split2/-/split2-4.2.0.tgz",
"integrity": "sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==",
"license": "ISC",
"engines": {
"node": ">= 10.x"
}
},
"node_modules/sprintf-js": { "node_modules/sprintf-js": {
"version": "1.0.3", "version": "1.0.3",
"resolved": "https://registry.npmjs.org/sprintf-js/-/sprintf-js-1.0.3.tgz", "resolved": "https://registry.npmjs.org/sprintf-js/-/sprintf-js-1.0.3.tgz",
@@ -22017,6 +22239,18 @@
"node": ">=14.15.0" "node": ">=14.15.0"
} }
}, },
"node_modules/thread-stream": {
"version": "4.0.0",
"resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-4.0.0.tgz",
"integrity": "sha512-4iMVL6HAINXWf1ZKZjIPcz5wYaOdPhtO8ATvZ+Xqp3BTdaqtAwQkNmKORqcIo5YkQqGXq5cwfswDwMqqQNrpJA==",
"license": "MIT",
"dependencies": {
"real-require": "^0.2.0"
},
"engines": {
"node": ">=20"
}
},
"node_modules/throat": { "node_modules/throat": {
"version": "5.0.0", "version": "5.0.0",
"resolved": "https://registry.npmjs.org/throat/-/throat-5.0.0.tgz", "resolved": "https://registry.npmjs.org/throat/-/throat-5.0.0.tgz",
@@ -24453,6 +24687,8 @@
"express-basic-auth": "^1.2.1", "express-basic-auth": "^1.2.1",
"mnemonic-id": "^3.2.7", "mnemonic-id": "^3.2.7",
"openai": "^4.20.0", "openai": "^4.20.0",
"pino": "^10.2.0",
"pino-pretty": "^13.1.3",
"playwright": "^1.56.1", "playwright": "^1.56.1",
"tiny-invariant": "^1.3.3", "tiny-invariant": "^1.3.3",
"uuid": "^9.0.1", "uuid": "^9.0.1",
+2
View File
@@ -39,6 +39,8 @@
"express-basic-auth": "^1.2.1", "express-basic-auth": "^1.2.1",
"mnemonic-id": "^3.2.7", "mnemonic-id": "^3.2.7",
"openai": "^4.20.0", "openai": "^4.20.0",
"pino": "^10.2.0",
"pino-pretty": "^13.1.3",
"playwright": "^1.56.1", "playwright": "^1.56.1",
"tiny-invariant": "^1.3.3", "tiny-invariant": "^1.3.3",
"uuid": "^9.0.1", "uuid": "^9.0.1",
+4 -4
View File
@@ -29,12 +29,12 @@ function spawnServer() {
// Restart on: explicit restart request, or any non-zero exit (crash) // Restart on: explicit restart request, or any non-zero exit (crash)
if (restarting || (code !== 0 && code !== null)) { if (restarting || (code !== 0 && code !== null)) {
restarting = false; restarting = false;
console.warn(`[DevRunner] Server exited (${exitDescriptor}). Restarting...`); process.stderr.write(`[DevRunner] Server exited (${exitDescriptor}). Restarting...\n`);
spawnServer(); spawnServer();
return; return;
} }
console.warn(`[DevRunner] Server exited (${exitDescriptor}). Shutting down.`); process.stderr.write(`[DevRunner] Server exited (${exitDescriptor}). Shutting down.\n`);
process.exit(0); process.exit(0);
}); });
} }
@@ -45,7 +45,7 @@ function restartServer() {
} }
restarting = true; restarting = true;
console.warn("[DevRunner] Restart requested. Stopping current server..."); process.stderr.write("[DevRunner] Restart requested. Stopping current server...\n");
child.kill("SIGTERM"); child.kill("SIGTERM");
} }
@@ -59,5 +59,5 @@ function forwardSignal(signal: NodeJS.Signals) {
process.on("SIGINT", () => forwardSignal("SIGINT")); process.on("SIGINT", () => forwardSignal("SIGINT"));
process.on("SIGTERM", () => forwardSignal("SIGTERM")); process.on("SIGTERM", () => forwardSignal("SIGTERM"));
console.log("[DevRunner] Starting server with tsx (explicit restarts only)"); process.stdout.write("[DevRunner] Starting server with tsx (explicit restarts only)\n");
spawnServer(); spawnServer();
@@ -7,24 +7,24 @@ async function processConversation() {
const conversationPath = const conversationPath =
".debug.conversations/ce44c79a-0689-4210-8e00-72c0a627406d-2.json"; ".debug.conversations/ce44c79a-0689-4210-8e00-72c0a627406d-2.json";
console.log("Loading conversation from:", conversationPath); process.stdout.write(`Loading conversation from: ${conversationPath}\n`);
const conversationData: any = JSON.parse( const conversationData: any = JSON.parse(
readFileSync(conversationPath, "utf-8") readFileSync(conversationPath, "utf-8")
); );
console.log( process.stdout.write(
`\nLoaded conversation ${conversationData.conversationId} with ${conversationData.messages.length} messages\n` `\nLoaded conversation ${conversationData.conversationId} with ${conversationData.messages.length} messages\n\n`
); );
const result = await standardizePrompt({ const result = await standardizePrompt({
prompt: conversationData.messages, prompt: conversationData.messages,
}); });
console.log("Standardized prompt result:"); process.stdout.write("Standardized prompt result:\n");
console.log(inspect(result, { depth: null, colors: true })); process.stdout.write(inspect(result, { depth: null, colors: true }) + "\n");
} catch (error) { } catch (error) {
console.error("Error processing conversation:", error); process.stderr.write(`Error processing conversation: ${error}\n`);
process.exit(1); process.exit(1);
} }
} }
@@ -30,7 +30,7 @@ async function main() {
(data) => { (data) => {
const event = (data.params as { msg: unknown }).msg as { type?: string }; const event = (data.params as { msg: unknown }).msg as { type?: string };
if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") { if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") {
console.log("MCP Event:", JSON.stringify(event, null, 2)); process.stdout.write("MCP Event: " + JSON.stringify(event, null, 2) + "\n");
} }
} }
); );
@@ -38,7 +38,7 @@ async function main() {
await client.connect(transport); await client.connect(transport);
// Use correct route (/mcp/agents) and bearer token env var // Use correct route (/mcp/agents) and bearer token env var
console.log("\n=== Testing HTTP MCP server with correct route and bearer token ===\n"); process.stdout.write("\n=== Testing HTTP MCP server with correct route and bearer token ===\n\n");
try { try {
const result = await client.callTool({ const result = await client.callTool({
@@ -58,18 +58,21 @@ async function main() {
} }
}, undefined, { timeout: 60000 }); }, undefined, { timeout: 60000 });
console.log("\n=== RESULT ==="); process.stdout.write("\n=== RESULT ===\n");
const content = (result as { content: { text?: string }[] }).content; const content = (result as { content: { text?: string }[] }).content;
for (const item of content) { for (const item of content) {
if (item.text) { if (item.text) {
console.log(item.text); process.stdout.write(item.text + "\n");
} }
} }
} catch (error) { } catch (error) {
console.error("Error:", error); process.stderr.write("Error: " + String(error) + "\n");
} }
await client.close(); await client.close();
} }
main().catch(console.error); main().catch((error) => {
process.stderr.write(String(error) + "\n");
process.exitCode = 1;
});
@@ -27,7 +27,7 @@ async function main() {
(data) => { (data) => {
const event = (data.params as { msg: unknown }).msg as { type?: string }; const event = (data.params as { msg: unknown }).msg as { type?: string };
if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") { if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") {
console.log("MCP Event:", JSON.stringify(event, null, 2)); process.stdout.write("MCP Event: " + JSON.stringify(event, null, 2) + "\n");
} }
} }
); );
@@ -35,7 +35,7 @@ async function main() {
await client.connect(transport); await client.connect(transport);
// Try passing MCP server config via the config parameter with headers // Try passing MCP server config via the config parameter with headers
console.log("\n=== Testing HTTP MCP server with basic auth in config ===\n"); process.stdout.write("\n=== Testing HTTP MCP server with basic auth in config ===\n\n");
try { try {
// Create base64 encoded credentials // Create base64 encoded credentials
@@ -61,18 +61,21 @@ async function main() {
} }
}, undefined, { timeout: 60000 }); }, undefined, { timeout: 60000 });
console.log("\n=== RESULT ==="); process.stdout.write("\n=== RESULT ===\n");
const content = (result as { content: { text?: string }[] }).content; const content = (result as { content: { text?: string }[] }).content;
for (const item of content) { for (const item of content) {
if (item.text) { if (item.text) {
console.log(item.text); process.stdout.write(item.text + "\n");
} }
} }
} catch (error) { } catch (error) {
console.error("Error:", error); process.stderr.write("Error: " + String(error) + "\n");
} }
await client.close(); await client.close();
} }
main().catch(console.error); main().catch((error) => {
process.stderr.write(String(error) + "\n");
process.exitCode = 1;
});
@@ -30,7 +30,7 @@ async function main() {
(data) => { (data) => {
const event = (data.params as { msg: unknown }).msg as { type?: string }; const event = (data.params as { msg: unknown }).msg as { type?: string };
if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") { if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") {
console.log("MCP Event:", JSON.stringify(event, null, 2)); process.stdout.write("MCP Event: " + JSON.stringify(event, null, 2) + "\n");
} }
} }
); );
@@ -38,7 +38,7 @@ async function main() {
await client.connect(transport); await client.connect(transport);
// Try passing MCP server config with bearer_token_env_var // Try passing MCP server config with bearer_token_env_var
console.log("\n=== Testing HTTP MCP server with bearer_token_env_var ===\n"); process.stdout.write("\n=== Testing HTTP MCP server with bearer_token_env_var ===\n\n");
try { try {
const result = await client.callTool({ const result = await client.callTool({
@@ -58,18 +58,21 @@ async function main() {
} }
}, undefined, { timeout: 60000 }); }, undefined, { timeout: 60000 });
console.log("\n=== RESULT ==="); process.stdout.write("\n=== RESULT ===\n");
const content = (result as { content: { text?: string }[] }).content; const content = (result as { content: { text?: string }[] }).content;
for (const item of content) { for (const item of content) {
if (item.text) { if (item.text) {
console.log(item.text); process.stdout.write(item.text + "\n");
} }
} }
} catch (error) { } catch (error) {
console.error("Error:", error); process.stderr.write("Error: " + String(error) + "\n");
} }
await client.close(); await client.close();
} }
main().catch(console.error); main().catch((error) => {
process.stderr.write(String(error) + "\n");
process.exitCode = 1;
});
@@ -28,7 +28,7 @@ async function main() {
(data) => { (data) => {
const event = (data.params as { msg: unknown }).msg as { type?: string }; const event = (data.params as { msg: unknown }).msg as { type?: string };
if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") { if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") {
console.log("MCP Event:", JSON.stringify(event, null, 2)); process.stdout.write("MCP Event: " + JSON.stringify(event, null, 2) + "\n");
} }
} }
); );
@@ -36,7 +36,7 @@ async function main() {
await client.connect(transport); await client.connect(transport);
// Test using http_headers with Authorization // Test using http_headers with Authorization
console.log("\n=== Testing HTTP MCP server with http_headers and Authorization ===\n"); process.stdout.write("\n=== Testing HTTP MCP server with http_headers and Authorization ===\n\n");
try { try {
const result = await client.callTool({ const result = await client.callTool({
@@ -58,18 +58,21 @@ async function main() {
} }
}, undefined, { timeout: 60000 }); }, undefined, { timeout: 60000 });
console.log("\n=== RESULT ==="); process.stdout.write("\n=== RESULT ===\n");
const content = (result as { content: { text?: string }[] }).content; const content = (result as { content: { text?: string }[] }).content;
for (const item of content) { for (const item of content) {
if (item.text) { if (item.text) {
console.log(item.text); process.stdout.write(item.text + "\n");
} }
} }
} catch (error) { } catch (error) {
console.error("Error:", error); process.stderr.write("Error: " + String(error) + "\n");
} }
await client.close(); await client.close();
} }
main().catch(console.error); main().catch((error) => {
process.stderr.write(String(error) + "\n");
process.exitCode = 1;
});
@@ -23,7 +23,7 @@ async function main() {
(data) => { (data) => {
const event = (data.params as { msg: unknown }).msg as { type?: string }; const event = (data.params as { msg: unknown }).msg as { type?: string };
if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") { if (event.type === "mcp_startup_update" || event.type === "mcp_startup_complete") {
console.log("MCP Event:", JSON.stringify(event, null, 2)); process.stdout.write("MCP Event: " + JSON.stringify(event, null, 2) + "\n");
} }
} }
); );
@@ -31,7 +31,7 @@ async function main() {
await client.connect(transport); await client.connect(transport);
// Try passing MCP server config via the config parameter with HTTP URL // Try passing MCP server config via the config parameter with HTTP URL
console.log("\n=== Testing HTTP MCP server config (agent-control style) ===\n"); process.stdout.write("\n=== Testing HTTP MCP server config (agent-control style) ===\n\n");
try { try {
const result = await client.callTool({ const result = await client.callTool({
@@ -51,18 +51,21 @@ async function main() {
} }
}, undefined, { timeout: 60000 }); }, undefined, { timeout: 60000 });
console.log("\n=== RESULT ==="); process.stdout.write("\n=== RESULT ===\n");
const content = (result as { content: { text?: string }[] }).content; const content = (result as { content: { text?: string }[] }).content;
for (const item of content) { for (const item of content) {
if (item.text) { if (item.text) {
console.log(item.text); process.stdout.write(item.text + "\n");
} }
} }
} catch (error) { } catch (error) {
console.error("Error:", error); process.stderr.write("Error: " + String(error) + "\n");
} }
await client.close(); await client.close();
} }
main().catch(console.error); main().catch((error) => {
process.stderr.write(String(error) + "\n");
process.exitCode = 1;
});
@@ -28,18 +28,18 @@ async function main() {
item?: { type?: string }; item?: { type?: string };
}; };
if (event.type === "turn.started") { if (event.type === "turn.started") {
console.log("\n=== TURN STARTED ==="); process.stdout.write("\n=== TURN STARTED ===\n");
} else if (event.type === "agent_message") { } else if (event.type === "agent_message") {
console.log("Agent:", event.data?.text || event.text); process.stdout.write("Agent: " + (event.data?.text || event.text) + "\n");
} else if (event.type === "mcp_tool_call") { } else if (event.type === "mcp_tool_call") {
console.log("MCP Tool Call:", JSON.stringify(event.data)); process.stdout.write("MCP Tool Call: " + JSON.stringify(event.data) + "\n");
} else if (event.type === "thread.item") { } else if (event.type === "thread.item") {
const item = event.data?.item || event.item; const item = event.data?.item || event.item;
if (item?.type === "mcp_tool_call") { if (item?.type === "mcp_tool_call") {
console.log("MCP Tool from thread:", JSON.stringify(item)); process.stdout.write("MCP Tool from thread: " + JSON.stringify(item) + "\n");
} }
} else { } else {
console.log("Event:", event.type); process.stdout.write("Event: " + event.type + "\n");
} }
} }
); );
@@ -47,7 +47,7 @@ async function main() {
await client.connect(transport); await client.connect(transport);
// Try passing MCP server config via the config parameter // Try passing MCP server config via the config parameter
console.log("\n=== Testing dynamic MCP server config ===\n"); process.stdout.write("\n=== Testing dynamic MCP server config ===\n\n");
try { try {
const result = await client.callTool({ const result = await client.callTool({
@@ -67,18 +67,21 @@ async function main() {
} }
}, undefined, { timeout: 60000 }); }, undefined, { timeout: 60000 });
console.log("\n=== RESULT ==="); process.stdout.write("\n=== RESULT ===\n");
const content = (result as { content: { text?: string }[] }).content; const content = (result as { content: { text?: string }[] }).content;
for (const item of content) { for (const item of content) {
if (item.text) { if (item.text) {
console.log(item.text); process.stdout.write(item.text + "\n");
} }
} }
} catch (error) { } catch (error) {
console.error("Error:", error); process.stderr.write("Error: " + String(error) + "\n");
} }
await client.close(); await client.close();
} }
main().catch(console.error); main().catch((error) => {
process.stderr.write(String(error) + "\n");
process.exitCode = 1;
});
@@ -4,8 +4,8 @@ import { buildPaseoDaemonConfigFromEnv } from "../src/server/config.js";
const config = buildPaseoDaemonConfigFromEnv(); const config = buildPaseoDaemonConfigFromEnv();
console.log("=== agentControlMcp config ==="); process.stdout.write("=== agentControlMcp config ===\n");
console.log(JSON.stringify(config.agentControlMcp, null, 2)); process.stdout.write(JSON.stringify(config.agentControlMcp, null, 2) + "\n");
// Simulate what buildCodexMcpConfig does // Simulate what buildCodexMcpConfig does
const mcpServers: Record<string, unknown> = {}; const mcpServers: Record<string, unknown> = {};
@@ -23,5 +23,5 @@ mcpServers["playwright"] = {
args: ["@playwright/mcp", "--headless", "--isolated"], args: ["@playwright/mcp", "--headless", "--isolated"],
}; };
console.log("\n=== Built MCP servers config ==="); process.stdout.write("\n=== Built MCP servers config ===\n");
console.log(JSON.stringify(mcpServers, null, 2)); process.stdout.write(JSON.stringify(mcpServers, null, 2) + "\n");
@@ -8,6 +8,7 @@ import {
SessionInboundMessageSchema, SessionInboundMessageSchema,
WSOutboundMessageSchema, WSOutboundMessageSchema,
} from "../shared/messages.js"; } from "../shared/messages.js";
import { getRootLogger } from "../server/logger.js";
import type { import type {
AgentStreamEventPayload, AgentStreamEventPayload,
AgentSnapshotPayload, AgentSnapshotPayload,
@@ -39,6 +40,8 @@ import type {
} from "../server/agent/agent-sdk-types.js"; } from "../server/agent/agent-sdk-types.js";
import { getAgentProviderDefinition } from "../server/agent/provider-manifest.js"; import { getAgentProviderDefinition } from "../server/agent/provider-manifest.js";
const logger = getRootLogger().child({ module: "daemon-client" });
export type DaemonTransport = { export type DaemonTransport = {
send: (data: string) => void; send: (data: string) => void;
close: (code?: number, reason?: string) => void; close: (code?: number, reason?: string) => void;
@@ -1409,7 +1412,7 @@ export class DaemonClientV2 {
const parsed = WSOutboundMessageSchema.safeParse(parsedJson); const parsed = WSOutboundMessageSchema.safeParse(parsedJson);
if (!parsed.success) { if (!parsed.success) {
const msgType = (parsedJson as { message?: { type?: string } })?.message?.type ?? "unknown"; const msgType = (parsedJson as { message?: { type?: string } })?.message?.type ?? "unknown";
console.warn(`[DaemonClientV2] Message validation failed for "${msgType}":`, parsed.error.message); logger.warn({ msgType, error: parsed.error.message }, "Message validation failed");
return; return;
} }
@@ -53,15 +53,6 @@ describe("Claude Agent SDK Commands POC", () => {
// Should be an array // Should be an array
expect(Array.isArray(commands)).toBe(true); expect(Array.isArray(commands)).toBe(true);
// Log what we found
console.log(`[Test] Found ${commands.length} commands:`);
commands.slice(0, 10).forEach((cmd) => {
console.log(` - /${cmd.name}: ${cmd.description} [${cmd.argumentHint}]`);
});
if (commands.length > 10) {
console.log(` ... and ${commands.length - 10} more`);
}
// Verify structure // Verify structure
if (commands.length > 0) { if (commands.length > 0) {
const firstCommand = commands[0]; const firstCommand = commands[0];
@@ -57,9 +57,9 @@ class Pushable<T> implements AsyncIterable<T> {
} }
async function investigateCommand(commandName: string): Promise<void> { async function investigateCommand(commandName: string): Promise<void> {
console.log(`\n${"=".repeat(60)}`); process.stdout.write(`\n${"=".repeat(60)}\n`);
console.log(`Investigating: /${commandName}`); process.stdout.write(`Investigating: /${commandName}\n`);
console.log("=".repeat(60)); process.stdout.write(`${"=".repeat(60)}\n`);
const input = new Pushable<SDKUserMessage>(); const input = new Pushable<SDKUserMessage>();
@@ -89,70 +89,70 @@ async function investigateCommand(commandName: string): Promise<void> {
let messageCount = 0; let messageCount = 0;
for await (const message of claudeQuery) { for await (const message of claudeQuery) {
messageCount++; messageCount++;
console.log(`\n--- Message ${messageCount} ---`); process.stdout.write(`\n--- Message ${messageCount} ---\n`);
console.log(`Type: ${message.type}`); process.stdout.write(`Type: ${message.type}\n`);
// Log the full structure based on type // Log the full structure based on type
switch (message.type) { switch (message.type) {
case "system": case "system":
console.log(`Subtype: ${message.subtype}`); process.stdout.write(`Subtype: ${message.subtype}\n`);
if (message.subtype === "init") { if (message.subtype === "init") {
console.log(`Session: ${message.session_id}`); process.stdout.write(`Session: ${message.session_id}\n`);
console.log(`Model: ${message.model}`); process.stdout.write(`Model: ${message.model}\n`);
} }
break; break;
case "user": case "user":
console.log(`User message content:`, JSON.stringify(message.message?.content, null, 2)); process.stdout.write(`User message content: ${JSON.stringify(message.message?.content, null, 2)}\n`);
break; break;
case "assistant": case "assistant":
console.log(`Assistant message content:`); process.stdout.write("Assistant message content:\n");
const content = message.message?.content; const content = message.message?.content;
if (Array.isArray(content)) { if (Array.isArray(content)) {
for (const block of content) { for (const block of content) {
console.log(` Block type: ${block.type}`); process.stdout.write(` Block type: ${block.type}\n`);
if (block.type === "text") { if (block.type === "text") {
console.log(` Text: ${block.text}`); process.stdout.write(` Text: ${block.text}\n`);
} else if (block.type === "tool_use") { } else if (block.type === "tool_use") {
console.log(` Tool: ${block.name}`); process.stdout.write(` Tool: ${block.name}\n`);
console.log(` Input: ${JSON.stringify(block.input, null, 2)}`); process.stdout.write(` Input: ${JSON.stringify(block.input, null, 2)}\n`);
} else { } else {
console.log(` Full block: ${JSON.stringify(block, null, 2)}`); process.stdout.write(` Full block: ${JSON.stringify(block, null, 2)}\n`);
} }
} }
} else { } else {
console.log(` Content: ${JSON.stringify(content, null, 2)}`); process.stdout.write(` Content: ${JSON.stringify(content, null, 2)}\n`);
} }
break; break;
case "stream_event": case "stream_event":
console.log(`Stream event type: ${message.event?.type}`); process.stdout.write(`Stream event type: ${message.event?.type}\n`);
if (message.event?.type === "content_block_delta") { if (message.event?.type === "content_block_delta") {
const delta = message.event.delta; const delta = message.event.delta;
if (delta?.type === "text_delta") { if (delta?.type === "text_delta") {
console.log(` Text delta: ${delta.text}`); process.stdout.write(` Text delta: ${delta.text}\n`);
} }
} }
break; break;
case "result": case "result":
console.log(`Result subtype: ${message.subtype}`); process.stdout.write(`Result subtype: ${message.subtype}\n`);
if ("errors" in message && message.errors) { if ("errors" in message && message.errors) {
console.log(`Errors: ${JSON.stringify(message.errors)}`); process.stdout.write(`Errors: ${JSON.stringify(message.errors)}\n`);
} }
// Check for any other properties // Check for any other properties
const resultKeys = Object.keys(message).filter(k => !["type", "subtype"].includes(k)); const resultKeys = Object.keys(message).filter(k => !["type", "subtype"].includes(k));
if (resultKeys.length > 0) { if (resultKeys.length > 0) {
console.log(`Other result properties: ${resultKeys.join(", ")}`); process.stdout.write(`Other result properties: ${resultKeys.join(", ")}\n`);
for (const key of resultKeys) { for (const key of resultKeys) {
console.log(` ${key}: ${JSON.stringify((message as any)[key], null, 2)}`); process.stdout.write(` ${key}: ${JSON.stringify((message as any)[key], null, 2)}\n`);
} }
} }
break; break;
default: default:
console.log(`Full message: ${JSON.stringify(message, null, 2)}`); process.stdout.write(`Full message: ${JSON.stringify(message, null, 2)}\n`);
} }
if (message.type === "result") { if (message.type === "result") {
@@ -160,7 +160,7 @@ async function investigateCommand(commandName: string): Promise<void> {
} }
} }
console.log(`\nTotal messages received: ${messageCount}`); process.stdout.write(`\nTotal messages received: ${messageCount}\n`);
} finally { } finally {
input.end(); input.end();
@@ -169,7 +169,7 @@ async function investigateCommand(commandName: string): Promise<void> {
} }
async function main() { async function main() {
console.log("=== Command Output Investigation ===\n"); process.stdout.write("=== Command Output Investigation ===\n\n");
// Test /context - a local command that shows context info // Test /context - a local command that shows context info
await investigateCommand("context"); await investigateCommand("context");
@@ -180,10 +180,10 @@ async function main() {
// Test /prompt-engineer - a SKILL (not a local command) // Test /prompt-engineer - a SKILL (not a local command)
await investigateCommand("prompt-engineer"); await investigateCommand("prompt-engineer");
console.log("\n=== Investigation Complete ==="); process.stdout.write("\n=== Investigation Complete ===\n");
} }
main().catch((error) => { main().catch((error) => {
console.error("Fatal error:", error); process.stderr.write(`Fatal error: ${error}\n`);
process.exit(1); process.exit(1);
}); });
+24 -24
View File
@@ -104,7 +104,7 @@ async function listAvailableCommands(): Promise<SlashCommand[]> {
} }
async function executeCommand(commandName: string): Promise<void> { async function executeCommand(commandName: string): Promise<void> {
console.log(`\n=== Executing command: /${commandName} ===`); process.stdout.write(`\n=== Executing command: /${commandName} ===\n`);
// For command execution, we need a proper input stream // For command execution, we need a proper input stream
const input = new Pushable<SDKUserMessage>(); const input = new Pushable<SDKUserMessage>();
@@ -136,12 +136,12 @@ async function executeCommand(commandName: string): Promise<void> {
// Iterate the query to process the command // Iterate the query to process the command
let gotSystemInit = false; let gotSystemInit = false;
for await (const message of claudeQuery) { for await (const message of claudeQuery) {
console.log(` [${message.type}]`, message.type === "system" ? message.subtype : ""); process.stdout.write(` [${message.type}] ${message.type === "system" ? message.subtype : ""}\n`);
if (message.type === "system" && message.subtype === "init") { if (message.type === "system" && message.subtype === "init") {
gotSystemInit = true; gotSystemInit = true;
console.log(" Session:", message.session_id); process.stdout.write(` Session: ${message.session_id}\n`);
console.log(" Model:", message.model); process.stdout.write(` Model: ${message.model}\n`);
} }
if (message.type === "assistant") { if (message.type === "assistant") {
@@ -149,14 +149,14 @@ async function executeCommand(commandName: string): Promise<void> {
if (Array.isArray(content)) { if (Array.isArray(content)) {
for (const block of content) { for (const block of content) {
if (block.type === "text") { if (block.type === "text") {
console.log(" Response:", block.text.slice(0, 200) + (block.text.length > 200 ? "..." : "")); process.stdout.write(` Response: ${block.text.slice(0, 200)}${block.text.length > 200 ? "..." : ""}\n`);
} }
} }
} }
} }
if (message.type === "result") { if (message.type === "result") {
console.log(" Result:", message.subtype); process.stdout.write(` Result: ${message.subtype}\n`);
break; break;
} }
} }
@@ -167,48 +167,48 @@ async function executeCommand(commandName: string): Promise<void> {
} }
async function main() { async function main() {
console.log("=== Claude Agent SDK Commands POC ===\n"); process.stdout.write("=== Claude Agent SDK Commands POC ===\n\n");
// PART 1: List available commands using supportedCommands() // PART 1: List available commands using supportedCommands()
console.log("=== Part 1: List Available Commands ===\n"); process.stdout.write("=== Part 1: List Available Commands ===\n\n");
try { try {
const commands = await listAvailableCommands(); const commands = await listAvailableCommands();
console.log(`Found ${commands.length} commands:\n`); process.stdout.write(`Found ${commands.length} commands:\n\n`);
commands.forEach((cmd, index) => { commands.forEach((cmd, index) => {
console.log(` ${index + 1}. /${cmd.name}`); process.stdout.write(` ${index + 1}. /${cmd.name}\n`);
console.log(` Description: ${cmd.description}`); process.stdout.write(` Description: ${cmd.description}\n`);
if (cmd.argumentHint) { if (cmd.argumentHint) {
console.log(` Arguments: ${cmd.argumentHint}`); process.stdout.write(` Arguments: ${cmd.argumentHint}\n`);
} }
console.log(""); process.stdout.write("\n");
}); });
// PART 2: Demonstrate command execution (optional - uncomment to test) // PART 2: Demonstrate command execution (optional - uncomment to test)
// Commands are just prompts sent with / prefix // Commands are just prompts sent with / prefix
console.log("=== Part 2: Command Execution Explanation ==="); process.stdout.write("=== Part 2: Command Execution Explanation ===\n");
console.log(""); process.stdout.write("\n");
console.log("Commands are executed by sending them as prompts with / prefix."); process.stdout.write("Commands are executed by sending them as prompts with / prefix.\n");
console.log("For example, to execute the 'help' command:"); process.stdout.write("For example, to execute the 'help' command:\n");
console.log(' 1. Create a user message with content: "/help"'); process.stdout.write(' 1. Create a user message with content: "/help"\n');
console.log(" 2. Push it to the input stream"); process.stdout.write(" 2. Push it to the input stream\n");
console.log(" 3. Iterate the query to receive responses"); process.stdout.write(" 3. Iterate the query to receive responses\n");
console.log(""); process.stdout.write("\n");
// Actually execute a command to demonstrate it works: // Actually execute a command to demonstrate it works:
// Using "context" as it's fast and doesn't require arguments // Using "context" as it's fast and doesn't require arguments
await executeCommand("context"); await executeCommand("context");
} catch (error) { } catch (error) {
console.error("ERROR:", error); process.stderr.write(`ERROR: ${error}\n`);
process.exit(1); process.exit(1);
} }
console.log("=== POC Complete ==="); process.stdout.write("=== POC Complete ===\n");
} }
main().catch((error) => { main().catch((error) => {
console.error("Fatal error:", error); process.stderr.write(`Fatal error: ${error}\n`);
process.exit(1); process.exit(1);
}); });
@@ -4,6 +4,9 @@ import {
AGENT_LIFECYCLE_STATUSES, AGENT_LIFECYCLE_STATUSES,
type AgentLifecycleStatus, type AgentLifecycleStatus,
} from "../../shared/agent-lifecycle.js"; } from "../../shared/agent-lifecycle.js";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", component: "agent-manager" });
import type { import type {
AgentCapabilityFlags, AgentCapabilityFlags,
@@ -268,9 +271,9 @@ export class AgentManager {
}); });
descriptors.push(...entries); descriptors.push(...entries);
} catch (error) { } catch (error) {
console.warn( logger.warn(
`[AgentManager] Failed to list persisted agents for provider '${provider}':`, { err: error, provider },
error "Failed to list persisted agents for provider"
); );
} }
} }
@@ -355,9 +358,9 @@ export class AgentManager {
try { try {
await existing.session.close(); await existing.session.close();
} catch (error) { } catch (error) {
console.warn( logger.warn(
`[AgentManager] Failed to close previous session for agent ${agentId} during refresh:`, { err: error, agentId },
error "Failed to close previous session during refresh"
); );
} }
@@ -546,9 +549,9 @@ export class AgentManager {
try { try {
await agent.session.interrupt(); await agent.session.interrupt();
} catch (error) { } catch (error) {
console.error( logger.error(
`[AgentManager] Failed to interrupt session for agent ${agentId}:`, { err: error, agentId },
error "Failed to interrupt session"
); );
} }
@@ -558,9 +561,9 @@ export class AgentManager {
await pendingRun.return(undefined as unknown as AgentStreamEvent); await pendingRun.return(undefined as unknown as AgentStreamEvent);
return true; return true;
} catch (error) { } catch (error) {
console.error( logger.error(
`[AgentManager] Failed to cancel run for agent ${agentId}:`, { err: error, agentId },
error "Failed to cancel run"
); );
throw error; throw error;
} }
@@ -464,7 +464,7 @@ describe("agent MCP end-to-end", () => {
throw new Error(`send_agent_prompt should interrupt running agent, but got: ${errorText}`); throw new Error(`send_agent_prompt should interrupt running agent, but got: ${errorText}`);
} }
// Other errors are OK - the main test is that we don't get "already has an active run" // Other errors are OK - the main test is that we don't get "already has an active run"
console.log(`send_agent_prompt returned error (not "already has an active run"): ${errorText}`);
} else { } else {
const secondPromptPayload = getStructuredContent(secondPromptResult); const secondPromptPayload = getStructuredContent(secondPromptResult);
expect(secondPromptPayload).toBeTruthy(); expect(secondPromptPayload).toBeTruthy();
@@ -2,6 +2,9 @@ import { randomUUID } from "node:crypto";
import { promises as fs } from "node:fs"; import { promises as fs } from "node:fs";
import path from "node:path"; import path from "node:path";
import { z } from "zod"; import { z } from "zod";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", component: "agent-registry" });
import { AgentStatusSchema } from "../messages.js"; import { AgentStatusSchema } from "../messages.js";
import { toStoredAgentRecord } from "./agent-projections.js"; import { toStoredAgentRecord } from "./agent-projections.js";
@@ -96,7 +99,7 @@ export class AgentRegistry {
this.cache.clear(); this.cache.clear();
return []; return [];
} }
console.error("[AgentRegistry] Failed to load agents:", error); logger.error({ err: error }, "Failed to load agents");
this.loaded = true; this.loaded = true;
this.cache.clear(); this.cache.clear();
return []; return [];
@@ -182,7 +185,7 @@ export class AgentRegistry {
records.push(record); records.push(record);
this.cache.set(record.id, record); this.cache.set(record.id, record);
} catch (error) { } catch (error) {
console.error("[AgentRegistry] Skipping invalid record:", error); logger.error({ err: error }, "Skipping invalid record");
} }
} }
return records; return records;
@@ -200,9 +203,7 @@ export class AgentRegistry {
try { try {
this.cache.clear(); this.cache.clear();
const records = this.parseRecords(candidate); const records = this.parseRecords(candidate);
console.warn( logger.warn("Recovered corrupted agents.json payload; rewrote sanitized copy");
"[AgentRegistry] Recovered corrupted agents.json payload; rewrote sanitized copy"
);
const sanitizedPayload = JSON.stringify(records, null, 2); const sanitizedPayload = JSON.stringify(records, null, 2);
await writeFileAtomically(this.filePath, sanitizedPayload); await writeFileAtomically(this.filePath, sanitizedPayload);
return records; return records;
+28 -22
View File
@@ -3,6 +3,10 @@ import { z } from "zod";
import { homedir } from "node:os"; import { homedir } from "node:os";
import { resolve } from "node:path"; import { resolve } from "node:path";
import { ensureValidJson } from "../json-utils.js"; import { ensureValidJson } from "../json-utils.js";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", component: "mcp-server" });
import type { import type {
AgentPromptInput, AgentPromptInput,
AgentProvider, AgentProvider,
@@ -184,9 +188,9 @@ function startAgentRun(
// Events are broadcast via AgentManager subscribers. // Events are broadcast via AgentManager subscribers.
} }
} catch (error) { } catch (error) {
console.error( logger.error(
`[Agent MCP] Agent stream failed for ${agentId}:`, { err: error, agentId },
error "Agent stream failed"
); );
} }
})(); })();
@@ -225,9 +229,9 @@ async function resolveAgentTitle(
const record = await agentRegistry.get(agentId); const record = await agentRegistry.get(agentId);
return record?.title ?? null; return record?.title ?? null;
} catch (error) { } catch (error) {
console.error( logger.error(
`[Agent MCP] Failed to load agent title for ${agentId}:`, { err: error, agentId },
error "Failed to load agent title"
); );
return null; return null;
} }
@@ -435,9 +439,9 @@ export async function createAgentMcpServer(
try { try {
agentManager.recordUserMessage(snapshot.id, initialPrompt); agentManager.recordUserMessage(snapshot.id, initialPrompt);
} catch (error) { } catch (error) {
console.error( logger.error(
`[Agent MCP] Failed to record initial prompt for ${snapshot.id}:`, { err: error, agentId: snapshot.id },
error "Failed to record initial prompt"
); );
} }
@@ -471,9 +475,9 @@ export async function createAgentMcpServer(
return response; return response;
} }
} catch (error) { } catch (error) {
console.error( logger.error(
`[Agent MCP] Failed to run initial prompt for ${snapshot.id}:`, { err: error, agentId: snapshot.id },
error "Failed to run initial prompt"
); );
} }
} else { } else {
@@ -616,14 +620,16 @@ export async function createAgentMcpServer(
} }
if (snapshot.lifecycle === "running" || snapshot.pendingRun) { if (snapshot.lifecycle === "running" || snapshot.pendingRun) {
console.log( logger.debug(
`[Agent MCP] Interrupting active run for ${agentId} before sending new prompt` { agentId },
"Interrupting active run before sending new prompt"
); );
try { try {
const cancelled = await agentManager.cancelAgentRun(agentId); const cancelled = await agentManager.cancelAgentRun(agentId);
if (!cancelled) { if (!cancelled) {
console.warn( logger.warn(
`[Agent MCP] Agent ${agentId} reported running but no active run was cancelled` { agentId },
"Agent reported running but no active run was cancelled"
); );
} }
// Also cancel any pending wait_for_agent calls for this agent // Also cancel any pending wait_for_agent calls for this agent
@@ -647,9 +653,9 @@ export async function createAgentMcpServer(
await new Promise((resolve) => setTimeout(resolve, pollIntervalMs)); await new Promise((resolve) => setTimeout(resolve, pollIntervalMs));
} }
} catch (error) { } catch (error) {
console.error( logger.error(
`[Agent MCP] Failed to interrupt agent ${agentId}:`, { err: error, agentId },
error "Failed to interrupt agent"
); );
throw error; throw error;
} }
@@ -662,9 +668,9 @@ export async function createAgentMcpServer(
try { try {
agentManager.recordUserMessage(agentId, prompt); agentManager.recordUserMessage(agentId, prompt);
} catch (error) { } catch (error) {
console.error( logger.error(
`[Agent MCP] Failed to record user message for ${agentId}:`, { err: error, agentId },
error "Failed to record user message"
); );
} }
@@ -1,6 +1,9 @@
import { fetchProviderModels } from "./provider-registry.js"; import { fetchProviderModels } from "./provider-registry.js";
import type { AgentProvider } from "./agent-sdk-types.js"; import type { AgentProvider } from "./agent-sdk-types.js";
import { expandTilde } from "../../utils/path.js"; import { expandTilde } from "../../utils/path.js";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", component: "model-resolver" });
type ResolveAgentModelOptions = { type ResolveAgentModelOptions = {
provider: AgentProvider; provider: AgentProvider;
@@ -23,9 +26,9 @@ export async function resolveAgentModel(
const preferred = models.find((model) => model.isDefault) ?? models[0]; const preferred = models.find((model) => model.isDefault) ?? models[0];
return preferred?.id; return preferred?.id;
} catch (error) { } catch (error) {
console.warn( logger.warn(
`[AgentModelResolver] Failed to resolve default model for ${options.provider}:`, { err: error, provider: options.provider },
error "Failed to resolve default model"
); );
return undefined; return undefined;
} }
@@ -51,9 +51,7 @@ describe("OpenCode reasoning events (e2e)", () => {
expect(agent.id).toBeTruthy(); expect(agent.id).toBeTruthy();
console.log("\n=== GPT-5 NANO E2E REASONING DEBUG ===\n");
console.log(`Agent ID: ${agent.id}`);
console.log(`Agent status: ${agent.status}`);
// Send a message that should trigger reasoning // Send a message that should trigger reasoning
await ctx.client.sendMessage(agent.id, "What is 2+2? Think step by step."); await ctx.client.sendMessage(agent.id, "What is 2+2? Think step by step.");
@@ -61,16 +59,14 @@ describe("OpenCode reasoning events (e2e)", () => {
// Wait for agent to complete // Wait for agent to complete
const finalState = await ctx.client.waitForAgentIdle(agent.id, 120_000); const finalState = await ctx.client.waitForAgentIdle(agent.id, 120_000);
console.log(`\nFinal status: ${finalState.status}`);
console.log(`Total events captured: ${allEvents.length}`);
// Log all events // Log all events
console.log("\n=== ALL EVENTS ===\n");
for (let i = 0; i < allEvents.length; i++) { for (let i = 0; i < allEvents.length; i++) {
const { event, timestamp } = allEvents[i]; const { event, timestamp } = allEvents[i];
console.log(`[EVENT ${i + 1}] timestamp=${timestamp} type=${event.type}`);
console.log(JSON.stringify(event, null, 2));
console.log("---");
} }
// Group by type // Group by type
@@ -78,9 +74,9 @@ describe("OpenCode reasoning events (e2e)", () => {
for (const { event } of allEvents) { for (const { event } of allEvents) {
byType.set(event.type, (byType.get(event.type) ?? 0) + 1); byType.set(event.type, (byType.get(event.type) ?? 0) + 1);
} }
console.log("\n=== EVENTS BY TYPE ===");
for (const [type, count] of byType) { for (const [type, count] of byType) {
console.log(` ${type}: ${count}`);
} }
// Check timeline events breakdown // Check timeline events breakdown
@@ -93,24 +89,24 @@ describe("OpenCode reasoning events (e2e)", () => {
itemTypes.set(event.item.type, (itemTypes.get(event.item.type) ?? 0) + 1); itemTypes.set(event.item.type, (itemTypes.get(event.item.type) ?? 0) + 1);
} }
} }
console.log("\n=== TIMELINE ITEM TYPES ===");
for (const [type, count] of itemTypes) { for (const [type, count] of itemTypes) {
console.log(` ${type}: ${count}`);
} }
// Find reasoning events // Find reasoning events
const reasoningEvents = timelineEvents.filter( const reasoningEvents = timelineEvents.filter(
({ event }) => event.type === "timeline" && event.item.type === "reasoning" ({ event }) => event.type === "timeline" && event.item.type === "reasoning"
); );
console.log(`\nReasoning events: ${reasoningEvents.length}`);
for (const { event } of reasoningEvents.slice(0, 5)) { for (const { event } of reasoningEvents.slice(0, 5)) {
if (event.type === "timeline") { if (event.type === "timeline") {
console.log("Sample reasoning:", JSON.stringify(event.item, null, 2));
} }
} }
// Check for duplicate consecutive events // Check for duplicate consecutive events
console.log("\n=== DUPLICATE CHECK ===");
let duplicateCount = 0; let duplicateCount = 0;
for (let i = 1; i < allEvents.length; i++) { for (let i = 1; i < allEvents.length; i++) {
const prev = allEvents[i - 1]; const prev = allEvents[i - 1];
@@ -118,13 +114,10 @@ describe("OpenCode reasoning events (e2e)", () => {
if (JSON.stringify(prev.event) === JSON.stringify(curr.event)) { if (JSON.stringify(prev.event) === JSON.stringify(curr.event)) {
duplicateCount++; duplicateCount++;
if (duplicateCount <= 5) { if (duplicateCount <= 5) {
console.log(`Duplicate at index ${i}:`, JSON.stringify(curr.event, null, 2));
} }
} }
} }
console.log(`Total duplicates: ${duplicateCount}`);
console.log("\n=== END DEBUG ===\n");
// HARD ASSERT: Agent completed // HARD ASSERT: Agent completed
expect(finalState.status).toBe("idle"); expect(finalState.status).toBe("idle");
@@ -48,7 +48,6 @@ describe("claude agent commands E2E", () => {
const commandNames = result.commands.map((c) => c.name); const commandNames = result.commands.map((c) => c.name);
// These are skills that come from CLAUDE.md configurations // These are skills that come from CLAUDE.md configurations
// At minimum we should have some commands available // At minimum we should have some commands available
console.log("Available commands:", commandNames);
expect(commandNames.length).toBeGreaterThan(0); expect(commandNames.length).toBeGreaterThan(0);
}, 120000); }, 120000);
@@ -52,11 +52,6 @@ describe("ClaudeAgentSession Commands", () => {
// Should have at least some built-in commands // Should have at least some built-in commands
expect(commands.length).toBeGreaterThan(0); expect(commands.length).toBeGreaterThan(0);
console.log(`[Test] Found ${commands.length} commands:`);
commands.slice(0, 5).forEach((cmd) => {
console.log(` - /${cmd.name}: ${cmd.description}`);
});
await session.close(); await session.close();
}, 30000); }, 30000);
@@ -91,9 +86,6 @@ describe("ClaudeAgentSession Commands", () => {
// The exact commands depend on what skills are configured // The exact commands depend on what skills are configured
expect(commands.length).toBeGreaterThan(0); expect(commands.length).toBeGreaterThan(0);
// Log all available commands for debugging
console.log(`[Test] Available commands: ${commandNames.join(", ")}`);
await session.close(); await session.close();
}, 30000); }, 30000);
}); });
@@ -111,7 +103,6 @@ describe("ClaudeAgentSession Commands", () => {
// Execute one of the available commands // Execute one of the available commands
const firstCommand = commands[0]; const firstCommand = commands[0];
console.log(`[Test] Executing command: /${firstCommand.name}`);
const result = await session.executeCommand!(firstCommand.name); const result = await session.executeCommand!(firstCommand.name);
// Should return a result object // Should return a result object
@@ -119,8 +110,6 @@ describe("ClaudeAgentSession Commands", () => {
expect(typeof result.text).toBe("string"); expect(typeof result.text).toBe("string");
// Note: Some commands may return empty text (e.g., plugin descriptions) // Note: Some commands may return empty text (e.g., plugin descriptions)
console.log(`[Test] Command /${firstCommand.name} result (first 200 chars): ${result.text.slice(0, 200)}...`);
await session.close(); await session.close();
}, 60000); }, 60000);
@@ -138,8 +127,6 @@ describe("ClaudeAgentSession Commands", () => {
expect(result.text.length).toBeGreaterThan(0); expect(result.text.length).toBeGreaterThan(0);
expect(result.text).toContain("Context"); expect(result.text).toContain("Context");
console.log(`[Test] Command /context result: ${result.text.slice(0, 300)}...`);
await session.close(); await session.close();
}, 60000); }, 60000);
@@ -158,7 +145,6 @@ describe("ClaudeAgentSession Commands", () => {
// Timeline may or may not have items depending on command execution // Timeline may or may not have items depending on command execution
// Just verify the structure is correct // Just verify the structure is correct
console.log(`[Test] Timeline has ${result.timeline.length} items`);
await session.close(); await session.close();
}, 60000); }, 60000);
@@ -145,8 +145,8 @@ async function startAgentMcpServer(): Promise<AgentMcpServerHandle> {
agentMcpTransports.delete(transport.sessionId); agentMcpTransports.delete(transport.sessionId);
} }
}; };
transport.onerror = (error) => { transport.onerror = () => {
console.error("[Agent MCP] Transport error:", error); // Ignore errors in test
}; };
await agentMcpServer.connect(transport); await agentMcpServer.connect(transport);
@@ -187,7 +187,6 @@ async function startAgentMcpServer(): Promise<AgentMcpServerHandle> {
await transport.handleRequest(req, res, req.body); await transport.handleRequest(req, res, req.body);
} catch (error) { } catch (error) {
console.error("[Agent MCP] Failed to handle request:", error);
if (!res.headersSent) { if (!res.headersSent) {
res.status(500).json({ res.status(500).json({
jsonrpc: "2.0", jsonrpc: "2.0",
@@ -20,6 +20,9 @@ import {
type SDKSystemMessage, type SDKSystemMessage,
type SDKUserMessage, type SDKUserMessage,
} from "@anthropic-ai/claude-agent-sdk"; } from "@anthropic-ai/claude-agent-sdk";
import { getRootLogger } from "../../logger.js";
const logger = getRootLogger().child({ module: "agent", provider: "claude" });
import type { import type {
AgentCapabilityFlags, AgentCapabilityFlags,
@@ -549,7 +552,7 @@ class ClaudeAgentSession implements AgentSession {
this.turnCancelRequested = true; this.turnCancelRequested = true;
// Store the interrupt promise so processPrompt can await it before calling query.next() // Store the interrupt promise so processPrompt can await it before calling query.next()
this.pendingInterruptPromise = this.interruptActiveTurn().catch((error) => { this.pendingInterruptPromise = this.interruptActiveTurn().catch((error) => {
console.warn("[ClaudeAgentSession] Failed to interrupt during cancel:", error); logger.warn({ err: error }, "Failed to interrupt during cancel");
}); });
// Push turn_canceled before ending the queue so consumers get proper lifecycle signals // Push turn_canceled before ending the queue so consumers get proper lifecycle signals
queue.push({ queue.push({
@@ -572,7 +575,7 @@ class ClaudeAgentSession implements AgentSession {
const forwardPromise = this.forwardPromptEvents(sdkMessage, queue, turnId); const forwardPromise = this.forwardPromptEvents(sdkMessage, queue, turnId);
this.activeTurnPromise = forwardPromise; this.activeTurnPromise = forwardPromise;
forwardPromise.catch((error) => { forwardPromise.catch((error) => {
console.error("[ClaudeAgentSession] Unexpected error in forwardPromptEvents:", error); logger.error({ err: error }, "Unexpected error in forwardPromptEvents");
}); });
try { try {
@@ -807,7 +810,7 @@ class ClaudeAgentSession implements AgentSession {
}, },
settingSources: ["user", "project"], settingSources: ["user", "project"],
stderr: (data: string) => { stderr: (data: string) => {
console.error("[ClaudeAgentSDK]", data.trim()); logger.error({ stderr: data.trim() }, "Claude Agent SDK stderr");
}, },
env: { env: {
...process.env, ...process.env,
@@ -1019,7 +1022,7 @@ class ClaudeAgentSession implements AgentSession {
this.query = null; this.query = null;
this.input = null; this.input = null;
} catch (error) { } catch (error) {
console.warn("[ClaudeAgentSession] Failed to interrupt active turn:", error); logger.warn({ err: error }, "Failed to interrupt active turn");
} }
} }
@@ -1097,7 +1100,7 @@ class ClaudeAgentSession implements AgentSession {
this.persistence = null; this.persistence = null;
// Capture actual model from SDK init message (not just the configured model) // Capture actual model from SDK init message (not just the configured model)
if (message.model) { if (message.model) {
console.log(`[ClaudeAgentSession] Captured model from SDK init: ${message.model}`); logger.debug({ model: message.model }, "Captured model from SDK init");
this.lastOptionsModel = message.model; this.lastOptionsModel = message.model;
// Invalidate cached runtime info so it picks up the new model // Invalidate cached runtime info so it picks up the new model
this.cachedRuntimeInfo = null; this.cachedRuntimeInfo = null;
@@ -73,15 +73,11 @@ describe("Claude SDK direct behavior", () => {
preset: "claude_code", preset: "claude_code",
}, },
settingSources: ["user", "project"], settingSources: ["user", "project"],
stderr: (data: string) => {
console.error("[SDK stderr]", data.trim());
},
}, },
}); });
try { try {
// Send first message // Send first message
console.log("[SDK] Sending MSG1");
input.push({ input.push({
type: "user", type: "user",
message: { role: "user", content: "Say exactly: MESSAGE_ONE" }, message: { role: "user", content: "Say exactly: MESSAGE_ONE" },
@@ -93,54 +89,32 @@ describe("Claude SDK direct behavior", () => {
const msg1Events: SDKMessage[] = []; const msg1Events: SDKMessage[] = [];
for await (const event of q) { for await (const event of q) {
msg1Events.push(event); msg1Events.push(event);
console.log("[SDK] MSG1 event:", event.type);
if (event.type === "assistant") { if (event.type === "assistant") {
// Push MSG2 BEFORE interrupt (like our wrapper does when a new message comes in) // Push MSG2 BEFORE interrupt (like our wrapper does when a new message comes in)
console.log("[SDK] Pushing MSG2 before interrupt...");
input.push({ input.push({
type: "user", type: "user",
message: { role: "user", content: "Say exactly: MESSAGE_TWO" }, message: { role: "user", content: "Say exactly: MESSAGE_TWO" },
parent_tool_use_id: null, parent_tool_use_id: null,
session_id: "", session_id: "",
}); });
console.log("[SDK] Calling interrupt()...");
await q.interrupt(); await q.interrupt();
console.log("[SDK] interrupt() returned");
break; break;
} }
if (event.type === "result") { if (event.type === "result") {
console.log("[SDK] MSG1 completed before interrupt");
break; break;
} }
} }
console.log("[SDK] MSG1 events:", msg1Events.length);
// MSG2 was already pushed before interrupt // MSG2 was already pushed before interrupt
console.log("[SDK] About to call q.next() for MSG2...");
const msg2Events: SDKMessage[] = []; const msg2Events: SDKMessage[] = [];
for await (const event of q) { for await (const event of q) {
msg2Events.push(event); msg2Events.push(event);
let detail = "";
if (event.type === "assistant" && "message" in event && event.message?.content) {
const content = event.message.content;
if (Array.isArray(content)) {
for (const block of content) {
if (block.type === "text" && block.text) {
detail = `"${block.text.substring(0, 50)}"`;
}
}
}
}
console.log("[SDK] MSG2 event:", event.type, detail);
if (event.type === "result") { if (event.type === "result") {
break; break;
} }
} }
console.log("[SDK] MSG2 loop finished");
// Analyze response // Analyze response
let responseText = ""; let responseText = "";
@@ -157,10 +131,6 @@ describe("Claude SDK direct behavior", () => {
} }
} }
console.log("[SDK] MSG2 response:", responseText);
console.log("[SDK] Mentions 'one':", responseText.toLowerCase().includes("one"));
console.log("[SDK] Mentions 'two':", responseText.toLowerCase().includes("two"));
const sawResult = msg2Events.some((event) => event.type === "result"); const sawResult = msg2Events.some((event) => event.type === "result");
// The SDK may short-circuit after interrupt without a result event. // The SDK may short-circuit after interrupt without a result event.
expect(sawResult || responseText.length === 0).toBe(true); expect(sawResult || responseText.length === 0).toBe(true);
@@ -14,6 +14,9 @@ import { Client } from "@modelcontextprotocol/sdk/client/index.js";
import { StdioClientTransport } from "@modelcontextprotocol/sdk/client/stdio.js"; import { StdioClientTransport } from "@modelcontextprotocol/sdk/client/stdio.js";
import { ElicitRequestSchema, type ElicitResult } from "@modelcontextprotocol/sdk/types.js"; import { ElicitRequestSchema, type ElicitResult } from "@modelcontextprotocol/sdk/types.js";
import { z } from "zod"; import { z } from "zod";
import { getRootLogger } from "../../logger.js";
const logger = getRootLogger().child({ module: "agent", provider: "codex" });
import type { import type {
AgentCapabilityFlags, AgentCapabilityFlags,
@@ -2377,8 +2380,9 @@ async function replaceInlineImageData(promptText: string): Promise<string> {
if (matches.length === 0) { if (matches.length === 0) {
return promptText; return promptText;
} }
console.info( logger.debug(
`[CodexAgentSession] Replacing ${matches.length} inline image data URL(s) with temp files.` { count: matches.length },
"Replacing inline image data URLs with temp files"
); );
let output = ""; let output = "";
let lastIndex = 0; let lastIndex = 0;
@@ -2393,9 +2397,7 @@ async function replaceInlineImageData(promptText: string): Promise<string> {
output += filePath; output += filePath;
} catch (error) { } catch (error) {
const message = error instanceof Error ? error.message : String(error); const message = error instanceof Error ? error.message : String(error);
console.warn( logger.warn({ message }, "Failed to replace inline image data URL");
`[CodexAgentSession] Failed to replace inline image data URL: ${message}`
);
output += fullMatch; output += fullMatch;
} }
lastIndex = matchIndex + fullMatch.length; lastIndex = matchIndex + fullMatch.length;
@@ -4845,9 +4847,9 @@ async function loadCodexPersistedTimeline(
const timeline = await parseRolloutFile(rolloutFile); const timeline = await parseRolloutFile(rolloutFile);
return timeline.slice(0, PERSISTED_TIMELINE_LIMIT); return timeline.slice(0, PERSISTED_TIMELINE_LIMIT);
} catch (error) { } catch (error) {
console.warn( logger.warn(
`[CodexMcpAgentSession] Failed to load persisted timeline for ${sessionId}:`, { err: error, sessionId },
error "Failed to load persisted timeline"
); );
return []; return [];
} }
@@ -1,6 +1,9 @@
import { spawn, type ChildProcess } from "node:child_process"; import { spawn, type ChildProcess } from "node:child_process";
import { createOpencodeClient, type OpencodeClient } from "@opencode-ai/sdk/v2/client"; import { createOpencodeClient, type OpencodeClient } from "@opencode-ai/sdk/v2/client";
import net from "node:net"; import net from "node:net";
import { getRootLogger } from "../../logger.js";
const logger = getRootLogger().child({ module: "agent", provider: "opencode" });
import type { import type {
AgentCapabilityFlags, AgentCapabilityFlags,
@@ -138,7 +141,7 @@ export class OpenCodeServerManager {
}); });
this.server.stderr?.on("data", (data: Buffer) => { this.server.stderr?.on("data", (data: Buffer) => {
console.error("[OpenCode Server]", data.toString().trim()); logger.error({ stderr: data.toString().trim() }, "OpenCode server stderr");
}); });
this.server.on("error", (error) => { this.server.on("error", (error) => {
@@ -1,6 +1,9 @@
import { mkdir, writeFile } from "fs/promises"; import { mkdir, writeFile } from "fs/promises";
import { join, resolve } from "path"; import { join, resolve } from "path";
import { inferAudioExtension, sanitizeForFilename } from "./audio-utils.js"; import { inferAudioExtension, sanitizeForFilename } from "./audio-utils.js";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", component: "stt-debug" });
const debugDir = process.env.STT_DEBUG_AUDIO_DIR const debugDir = process.env.STT_DEBUG_AUDIO_DIR
? resolve(process.env.STT_DEBUG_AUDIO_DIR) ? resolve(process.env.STT_DEBUG_AUDIO_DIR)
@@ -24,7 +27,7 @@ export async function maybePersistDebugAudio(
} }
if (!announced) { if (!announced) {
console.log(`[STT][Debug] Raw audio capture enabled at ${debugDir}`); logger.info({ debugDir }, "Raw audio capture enabled");
announced = true; announced = true;
} }
+13 -13
View File
@@ -1,5 +1,6 @@
import { transcribeAudio, type TranscriptionResult } from "./stt-openai.js"; import { transcribeAudio, type TranscriptionResult } from "./stt-openai.js";
import { maybePersistDebugAudio } from "./stt-debug.js"; import { maybePersistDebugAudio } from "./stt-debug.js";
import { getRootLogger } from "../logger.js";
interface TranscriptionMetadata { interface TranscriptionMetadata {
agentId?: string; agentId?: string;
@@ -19,9 +20,11 @@ export interface SessionTranscriptionResult extends TranscriptionResult {
*/ */
export class STTManager { export class STTManager {
private readonly sessionId: string; private readonly sessionId: string;
private readonly logger;
constructor(sessionId: string) { constructor(sessionId: string) {
this.sessionId = sessionId; this.sessionId = sessionId;
this.logger = getRootLogger().child({ module: "agent", component: "stt-manager", sessionId });
} }
/** /**
@@ -32,9 +35,9 @@ export class STTManager {
format: string, format: string,
metadata?: TranscriptionMetadata metadata?: TranscriptionMetadata
): Promise<SessionTranscriptionResult> { ): Promise<SessionTranscriptionResult> {
const context = metadata?.label ? ` (${metadata.label})` : ""; this.logger.debug(
console.log( { bytes: audio.length, format, label: metadata?.label },
`[STT-Manager ${this.sessionId}] Transcribing ${audio.length} bytes of ${format} audio${context}` "Transcribing audio"
); );
let debugRecordingPath: string | null = null; let debugRecordingPath: string | null = null;
@@ -47,18 +50,16 @@ export class STTManager {
format, format,
}); });
} catch (error) { } catch (error) {
console.warn( this.logger.warn({ err: error }, "Failed to persist debug audio");
`[STT-Manager ${this.sessionId}] Failed to persist debug audio:`,
error
);
} }
const result = await transcribeAudio(audio, format); const result = await transcribeAudio(audio, format);
// Filter out low-confidence transcriptions (non-speech sounds) // Filter out low-confidence transcriptions (non-speech sounds)
if (result.isLowConfidence) { if (result.isLowConfidence) {
console.log( this.logger.debug(
`[STT-Manager ${this.sessionId}] Filtered low-confidence transcription (likely non-speech): "${result.text}" (avg logprob: ${result.avgLogprob?.toFixed(2)})` { text: result.text, avgLogprob: result.avgLogprob },
"Filtered low-confidence transcription (likely non-speech)"
); );
// Return empty text to ignore this transcription // Return empty text to ignore this transcription
@@ -71,10 +72,9 @@ export class STTManager {
}; };
} }
console.log( this.logger.debug(
`[STT-Manager ${this.sessionId}] Transcription complete: "${result.text}"${ { text: result.text, avgLogprob: result.avgLogprob },
result.avgLogprob !== undefined ? ` (avg logprob: ${result.avgLogprob.toFixed(2)})` : "" "Transcription complete"
}`
); );
return { return {
+20 -19
View File
@@ -4,6 +4,9 @@ import { join } from "path";
import { tmpdir } from "os"; import { tmpdir } from "os";
import { v4 } from "uuid"; import { v4 } from "uuid";
import { inferAudioExtension } from "./audio-utils.js"; import { inferAudioExtension } from "./audio-utils.js";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", provider: "openai", component: "stt" });
export interface STTConfig { export interface STTConfig {
apiKey: string; apiKey: string;
@@ -58,7 +61,7 @@ export function initializeSTT(sttConfig: STTConfig): void {
openaiClient = new OpenAI({ openaiClient = new OpenAI({
apiKey: sttConfig.apiKey, apiKey: sttConfig.apiKey,
}); });
console.log("✓ STT (OpenAI Whisper) initialized"); logger.info({ model: sttConfig.model || "whisper-1" }, "STT (OpenAI Whisper) initialized");
} }
export async function transcribeAudio( export async function transcribeAudio(
@@ -81,8 +84,9 @@ export async function transcribeAudio(
tempFilePath = join(tmpdir(), `audio-${v4()}.${ext}`); tempFilePath = join(tmpdir(), `audio-${v4()}.${ext}`);
await writeFile(tempFilePath, audioBuffer); await writeFile(tempFilePath, audioBuffer);
console.log( logger.debug(
`[STT] Transcribing audio file: ${tempFilePath} (${audioBuffer.length} bytes)` { tempFilePath, bytes: audioBuffer.length },
"Transcribing audio file"
); );
// Call OpenAI Whisper API // Call OpenAI Whisper API
@@ -126,24 +130,21 @@ export async function transcribeAudio(
isLowConfidence = avgLogprob < confidenceThreshold; isLowConfidence = avgLogprob < confidenceThreshold;
if (isLowConfidence) { if (isLowConfidence) {
console.log( logger.debug(
`[STT] Low confidence transcription detected (avg: ${avgLogprob.toFixed( {
2 avgLogprob,
)}, threshold: ${confidenceThreshold}): "${response.text}"` threshold: confidenceThreshold,
); text: response.text,
console.log( tokenLogprobs: logprobs.map((t) => `${t.token}:${t.logprob.toFixed(2)}`).join(", ")
`[STT] Token logprobs:`, },
logprobs.map((t) => `${t.token}:${t.logprob.toFixed(2)}`).join(", ") "Low confidence transcription detected"
); );
} }
} }
console.log( logger.debug(
`[STT] Transcription complete in ${duration}ms: "${response.text}"${ { duration, text: response.text, avgLogprob },
avgLogprob !== undefined "Transcription complete"
? ` (avg logprob: ${avgLogprob.toFixed(2)})`
: ""
}`
); );
return { return {
@@ -158,7 +159,7 @@ export async function transcribeAudio(
: undefined, : undefined,
}; };
} catch (error: any) { } catch (error: any) {
console.error("[STT] Transcription error:", error); logger.error({ err: error }, "Transcription error");
throw new Error(`STT transcription failed: ${error.message}`); throw new Error(`STT transcription failed: ${error.message}`);
} finally { } finally {
// Clean up temporary file // Clean up temporary file
@@ -166,7 +167,7 @@ export async function transcribeAudio(
try { try {
await unlink(tempFilePath); await unlink(tempFilePath);
} catch (cleanupError) { } catch (cleanupError) {
console.warn(`[STT] Failed to clean up temp file: ${tempFilePath}`); logger.warn({ tempFilePath }, "Failed to clean up temp file");
} }
} }
} }
+18 -38
View File
@@ -1,6 +1,7 @@
import { v4 as uuidv4 } from "uuid"; import { v4 as uuidv4 } from "uuid";
import { synthesizeSpeech } from "./tts-openai.js"; import { synthesizeSpeech } from "./tts-openai.js";
import type { SessionOutboundMessage } from "../messages.js"; import type { SessionOutboundMessage } from "../messages.js";
import { getRootLogger } from "../logger.js";
interface PendingPlayback { interface PendingPlayback {
resolve: () => void; resolve: () => void;
@@ -15,10 +16,10 @@ interface PendingPlayback {
*/ */
export class TTSManager { export class TTSManager {
private pendingPlaybacks: Map<string, PendingPlayback> = new Map(); private pendingPlaybacks: Map<string, PendingPlayback> = new Map();
private readonly sessionId: string; private readonly logger;
constructor(sessionId: string) { constructor(sessionId: string) {
this.sessionId = sessionId; this.logger = getRootLogger().child({ module: "agent", component: "tts-manager", sessionId });
} }
/** /**
@@ -32,9 +33,7 @@ export class TTSManager {
isRealtimeMode: boolean isRealtimeMode: boolean
): Promise<void> { ): Promise<void> {
if (abortSignal.aborted) { if (abortSignal.aborted) {
console.log( this.logger.debug("Aborted before generating audio");
`[TTS-Manager ${this.sessionId}] Aborted before generating audio`
);
return; return;
} }
@@ -42,9 +41,7 @@ export class TTSManager {
const { stream, format } = await synthesizeSpeech(text); const { stream, format } = await synthesizeSpeech(text);
if (abortSignal.aborted) { if (abortSignal.aborted) {
console.log( this.logger.debug("Aborted after generating audio");
`[TTS-Manager ${this.sessionId}] Aborted after generating audio`
);
return; return;
} }
@@ -74,9 +71,7 @@ export class TTSManager {
}; };
onAbort = () => { onAbort = () => {
console.log( this.logger.debug("Aborted while waiting for playback");
`[TTS-Manager ${this.sessionId}] Aborted while waiting for playback`
);
pendingPlayback.streamEnded = true; pendingPlayback.streamEnded = true;
pendingPlayback.pendingChunks = 0; pendingPlayback.pendingChunks = 0;
this.pendingPlaybacks.delete(audioId); this.pendingPlaybacks.delete(audioId);
@@ -96,9 +91,7 @@ export class TTSManager {
while (true) { while (true) {
if (abortSignal.aborted) { if (abortSignal.aborted) {
console.log( this.logger.debug("Aborted during stream emission");
`[TTS-Manager ${this.sessionId}] Aborted during stream emission`
);
break; break;
} }
@@ -122,10 +115,9 @@ export class TTSManager {
}, },
}); });
console.log( this.logger.debug(
`[TTS-Manager ${this.sessionId}] ${new Date().toISOString()} Sent audio chunk ${chunkId}${ { chunkId, isLastChunk: next.done },
next.done ? " (last)" : "" "Sent audio chunk"
}`
); );
chunkIndex += 1; chunkIndex += 1;
@@ -149,14 +141,9 @@ export class TTSManager {
await playbackPromise; await playbackPromise;
} catch (error) { } catch (error) {
if (abortSignal.aborted) { if (abortSignal.aborted) {
console.log( this.logger.debug("Audio stream closed after abort");
`[TTS-Manager ${this.sessionId}] Audio stream closed after abort`
);
} else { } else {
console.error( this.logger.error({ err: error }, "Error streaming audio");
`[TTS-Manager ${this.sessionId}] Error streaming audio`,
error
);
this.pendingPlaybacks.delete(audioId); this.pendingPlaybacks.delete(audioId);
pendingPlayback.reject(error as Error); pendingPlayback.reject(error as Error);
throw error; throw error;
@@ -172,11 +159,7 @@ export class TTSManager {
return; return;
} }
console.log( this.logger.debug({ audioId }, "Audio playback confirmed");
`[TTS-Manager ${
this.sessionId
}] ${new Date().toISOString()} Audio ${audioId} playback confirmed`
);
} }
/** /**
@@ -190,9 +173,7 @@ export class TTSManager {
const pending = this.pendingPlaybacks.get(audioId); const pending = this.pendingPlaybacks.get(audioId);
if (!pending) { if (!pending) {
console.warn( this.logger.warn({ chunkId }, "Received confirmation for unknown audio ID");
`[TTS-Manager ${this.sessionId}] Received confirmation for unknown audio ID: ${chunkId}`
);
return; return;
} }
@@ -212,16 +193,15 @@ export class TTSManager {
return; return;
} }
console.log( this.logger.debug(
`[TTS-Manager ${this.sessionId}] Cancelling ${this.pendingPlaybacks.size} pending playback(s): ${reason}` { count: this.pendingPlaybacks.size, reason },
"Cancelling pending playbacks"
); );
for (const [audioId, pending] of this.pendingPlaybacks.entries()) { for (const [audioId, pending] of this.pendingPlaybacks.entries()) {
pending.resolve(); pending.resolve();
this.pendingPlaybacks.delete(audioId); this.pendingPlaybacks.delete(audioId);
console.log( this.logger.debug({ audioId }, "Cleared pending playback");
`[TTS-Manager ${this.sessionId}] Cleared pending playback ${audioId}`
);
} }
} }
+11 -8
View File
@@ -1,5 +1,8 @@
import OpenAI from "openai"; import OpenAI from "openai";
import { Readable } from "stream"; import { Readable } from "stream";
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", provider: "openai", component: "tts" });
export interface TTSConfig { export interface TTSConfig {
apiKey: string; apiKey: string;
@@ -26,8 +29,9 @@ export function initializeTTS(ttsConfig: TTSConfig): void {
openaiClient = new OpenAI({ openaiClient = new OpenAI({
apiKey: ttsConfig.apiKey, apiKey: ttsConfig.apiKey,
}); });
console.log( logger.info(
`✓ TTS (OpenAI) initialized with voice: ${config.voice}, model: ${config.model}, format: ${config.responseFormat}` { voice: config.voice, model: config.model, format: config.responseFormat },
"TTS (OpenAI) initialized"
); );
} }
@@ -45,10 +49,9 @@ export async function synthesizeSpeech(
const startTime = Date.now(); const startTime = Date.now();
try { try {
console.log( logger.debug(
`[TTS] Synthesizing speech: "${text.substring(0, 50)}${ { textLength: text.length, preview: text.substring(0, 50) },
text.length > 50 ? "..." : "" "Synthesizing speech"
}"`
); );
// Call OpenAI TTS API with streaming // Call OpenAI TTS API with streaming
@@ -63,14 +66,14 @@ export async function synthesizeSpeech(
const audioStream = response.body as unknown as Readable; const audioStream = response.body as unknown as Readable;
const duration = Date.now() - startTime; const duration = Date.now() - startTime;
console.log(`[TTS] Speech synthesis stream ready in ${duration}ms`); logger.debug({ duration }, "Speech synthesis stream ready");
return { return {
stream: audioStream, stream: audioStream,
format: config.responseFormat || "mp3", format: config.responseFormat || "mp3",
}; };
} catch (error: any) { } catch (error: any) {
console.error("[TTS] Speech synthesis error:", error); logger.error({ err: error }, "Speech synthesis error");
throw new Error(`TTS synthesis failed: ${error.message}`); throw new Error(`TTS synthesis failed: ${error.message}`);
} }
} }
@@ -1,3 +1,7 @@
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "agent", component: "wait-for-agent-tracker" });
export type WaitForAgentCanceler = (agentId: string, reason?: string) => boolean; export type WaitForAgentCanceler = (agentId: string, reason?: string) => boolean;
/** /**
@@ -37,9 +41,9 @@ export class WaitForAgentTracker {
try { try {
cancel(reason); cancel(reason);
} catch (error) { } catch (error) {
console.warn( logger.warn(
`[WaitForAgentTracker] Cancel callback failed for ${agentId}:`, { err: error, agentId },
error "Cancel callback failed"
); );
} }
} }
+39 -33
View File
@@ -6,6 +6,7 @@ import { stat } from "fs/promises";
import { randomUUID } from "node:crypto"; import { randomUUID } from "node:crypto";
import { StreamableHTTPServerTransport } from "@modelcontextprotocol/sdk/server/streamableHttp.js"; import { StreamableHTTPServerTransport } from "@modelcontextprotocol/sdk/server/streamableHttp.js";
import { isInitializeRequest } from "@modelcontextprotocol/sdk/types.js"; import { isInitializeRequest } from "@modelcontextprotocol/sdk/types.js";
import { getRootLogger } from "./logger.js";
type ListenTarget = type ListenTarget =
| { type: "tcp"; host: string; port: number } | { type: "tcp"; host: string; port: number }
@@ -96,6 +97,8 @@ export interface PaseoDaemon {
export async function createPaseoDaemon( export async function createPaseoDaemon(
config: PaseoDaemonConfig config: PaseoDaemonConfig
): Promise<PaseoDaemon> { ): Promise<PaseoDaemon> {
const logger = getRootLogger().child({ module: "bootstrap" });
const agentMcpRoute = config.agentMcpRoute; const agentMcpRoute = config.agentMcpRoute;
const basicAuthUsers = config.auth.basicUsers; const basicAuthUsers = config.auth.basicUsers;
const staticDir = config.staticDir; const staticDir = config.staticDir;
@@ -176,8 +179,8 @@ export async function createPaseoDaemon(
try { try {
const conversations = await listConversations(); const conversations = await listConversations();
res.json(conversations); res.json(conversations);
} catch (error) { } catch (err) {
console.error("[API] Failed to list conversations:", error); logger.error({ err }, "Failed to list conversations");
res.status(500).json({ error: "Failed to list conversations" }); res.status(500).json({ error: "Failed to list conversations" });
} }
}); });
@@ -187,8 +190,8 @@ export async function createPaseoDaemon(
const { id } = req.params; const { id } = req.params;
await deleteConversation(id); await deleteConversation(id);
res.json({ success: true }); res.json({ success: true });
} catch (error) { } catch (err) {
console.error("[API] Failed to delete conversation:", error); logger.error({ err }, "Failed to delete conversation");
res.status(500).json({ error: "Failed to delete conversation" }); res.status(500).json({ error: "Failed to delete conversation" });
} }
}); });
@@ -226,8 +229,8 @@ export async function createPaseoDaemon(
res.setHeader("Content-Length", entry.size.toString()); res.setHeader("Content-Length", entry.size.toString());
const stream = createReadStream(entry.absolutePath); const stream = createReadStream(entry.absolutePath);
stream.on("error", (error) => { stream.on("error", (err) => {
console.error("[API] Failed to stream download:", error); logger.error({ err }, "Failed to stream download");
if (!res.headersSent) { if (!res.headersSent) {
res.status(500).json({ error: "Failed to read file" }); res.status(500).json({ error: "Failed to read file" });
} else { } else {
@@ -235,8 +238,8 @@ export async function createPaseoDaemon(
} }
}); });
stream.pipe(res); stream.pipe(res);
} catch (error) { } catch (err) {
console.error("[API] Failed to download file:", error); logger.error({ err }, "Failed to download file");
if (!res.headersSent) { if (!res.headersSent) {
res.status(404).json({ error: "File not found" }); res.status(404).json({ error: "File not found" });
} }
@@ -257,8 +260,8 @@ export async function createPaseoDaemon(
attachAgentRegistryPersistence(agentManager, agentRegistry); attachAgentRegistryPersistence(agentManager, agentRegistry);
const persistedRecords = await agentRegistry.list(); const persistedRecords = await agentRegistry.list();
console.log( logger.info(
`✓ Agent registry loaded (${persistedRecords.length} record${persistedRecords.length === 1 ? "" : "s"}); agents will initialize on demand` `Agent registry loaded (${persistedRecords.length} record${persistedRecords.length === 1 ? "" : "s"}); agents will initialize on demand`
); );
const agentMcpTransports: AgentMcpTransportMap = new Map(); const agentMcpTransports: AgentMcpTransportMap = new Map();
@@ -275,11 +278,11 @@ export async function createPaseoDaemon(
sessionIdGenerator: () => randomUUID(), sessionIdGenerator: () => randomUUID(),
onsessioninitialized: (sessionId) => { onsessioninitialized: (sessionId) => {
agentMcpTransports.set(sessionId, transport); agentMcpTransports.set(sessionId, transport);
console.log(`[Agent MCP] Session initialized: ${sessionId}`); logger.debug({ sessionId }, "Agent MCP session initialized");
}, },
onsessionclosed: (sessionId) => { onsessionclosed: (sessionId) => {
agentMcpTransports.delete(sessionId); agentMcpTransports.delete(sessionId);
console.log(`[Agent MCP] Session closed: ${sessionId}`); logger.debug({ sessionId }, "Agent MCP session closed");
}, },
enableDnsRebindingProtection: true, enableDnsRebindingProtection: true,
allowedHosts, allowedHosts,
@@ -289,8 +292,8 @@ export async function createPaseoDaemon(
agentMcpTransports.delete(transport.sessionId); agentMcpTransports.delete(transport.sessionId);
} }
}; };
transport.onerror = (error) => { transport.onerror = (err) => {
console.error("[Agent MCP] Transport error:", error); logger.error({ err }, "Agent MCP transport error");
}; };
await agentMcpServer.connect(transport); await agentMcpServer.connect(transport);
@@ -300,13 +303,16 @@ export async function createPaseoDaemon(
const handleAgentMcpRequest: express.RequestHandler = async (req, res) => { const handleAgentMcpRequest: express.RequestHandler = async (req, res) => {
if (config.mcpDebug) { if (config.mcpDebug) {
console.log("[Agent MCP] request", { logger.debug(
method: req.method, {
url: req.originalUrl, method: req.method,
sessionId: req.header("mcp-session-id"), url: req.originalUrl,
authorization: req.header("authorization"), sessionId: req.header("mcp-session-id"),
body: req.body, authorization: req.header("authorization"),
}); body: req.body,
},
"Agent MCP request"
);
} }
try { try {
const sessionId = req.header("mcp-session-id"); const sessionId = req.header("mcp-session-id");
@@ -346,8 +352,8 @@ export async function createPaseoDaemon(
} }
await transport.handleRequest(req as any, res as any, req.body); await transport.handleRequest(req as any, res as any, req.body);
} catch (error) { } catch (err) {
console.error("[Agent MCP] Failed to handle request:", error); logger.error({ err }, "Failed to handle Agent MCP request");
if (!res.headersSent) { if (!res.headersSent) {
res.status(500).json({ res.status(500).json({
jsonrpc: "2.0", jsonrpc: "2.0",
@@ -364,7 +370,7 @@ export async function createPaseoDaemon(
app.post(agentMcpRoute, handleAgentMcpRequest); app.post(agentMcpRoute, handleAgentMcpRequest);
app.get(agentMcpRoute, handleAgentMcpRequest); app.get(agentMcpRoute, handleAgentMcpRequest);
app.delete(agentMcpRoute, handleAgentMcpRequest); app.delete(agentMcpRoute, handleAgentMcpRequest);
console.log(`✓ Agent MCP server mounted at ${agentMcpRoute}`); logger.info({ route: agentMcpRoute }, "Agent MCP server mounted");
const wsServer = new VoiceAssistantWebSocketServer( const wsServer = new VoiceAssistantWebSocketServer(
httpServer, httpServer,
@@ -380,7 +386,7 @@ export async function createPaseoDaemon(
const openaiApiKey = config.openai?.apiKey; const openaiApiKey = config.openai?.apiKey;
if (openaiApiKey) { if (openaiApiKey) {
console.log("✓ OpenAI client initialized"); logger.info("OpenAI client initialized");
const sttApiKey = config.openai?.stt?.apiKey ?? openaiApiKey; const sttApiKey = config.openai?.stt?.apiKey ?? openaiApiKey;
if (sttApiKey) { if (sttApiKey) {
@@ -405,9 +411,7 @@ export async function createPaseoDaemon(
initializeTitleGenerator(openaiApiKey); initializeTitleGenerator(openaiApiKey);
} else { } else {
console.warn( logger.warn("OPENAI_API_KEY not set - LLM, STT, and TTS features will not work");
"⚠ OPENAI_API_KEY not set - LLM, STT, and TTS features will not work"
);
} }
const start = async () => { const start = async () => {
@@ -419,11 +423,12 @@ export async function createPaseoDaemon(
const onListening = () => { const onListening = () => {
httpServer.off("error", onError); httpServer.off("error", onError);
if (listenTarget.type === "tcp") { if (listenTarget.type === "tcp") {
console.log( logger.info(
`✓ Server listening on http://${listenTarget.host}:${listenTarget.port}` { host: listenTarget.host, port: listenTarget.port },
`Server listening on http://${listenTarget.host}:${listenTarget.port}`
); );
} else { } else {
console.log(`✓ Server listening on ${listenTarget.path}`); logger.info({ path: listenTarget.path }, `Server listening on ${listenTarget.path}`);
} }
resolve(); resolve();
}; };
@@ -465,12 +470,13 @@ export async function createPaseoDaemon(
} }
async function closeAllAgents(agentManager: AgentManager): Promise<void> { async function closeAllAgents(agentManager: AgentManager): Promise<void> {
const logger = getRootLogger().child({ module: "bootstrap" });
const agents = agentManager.listAgents(); const agents = agentManager.listAgents();
for (const agent of agents) { for (const agent of agents) {
try { try {
await agentManager.closeAgent(agent.id); await agentManager.closeAgent(agent.id);
} catch (error) { } catch (err) {
console.error(`[Agents] Failed to close agent ${agent.id}:`, error); logger.error({ err, agentId: agent.id }, "Failed to close agent");
} }
} }
} }
+50 -105
View File
@@ -2177,10 +2177,8 @@ describe("daemon E2E", () => {
// Concatenate all chunks to form the complete response // Concatenate all chunks to form the complete response
const fullResponse = assistantChunks.join(""); const fullResponse = assistantChunks.join("");
console.log("[STREAMING TEXT INTEGRITY TEST]");
console.log("Number of chunks:", assistantChunks.length);
console.log("Full response:", JSON.stringify(fullResponse));
console.log("Individual chunks:", assistantChunks.map((c, i) => `[${i}]: ${JSON.stringify(c)}`).join("\n"));
// CRITICAL ASSERTION 1: Response should not be empty // CRITICAL ASSERTION 1: Response should not be empty
expect(fullResponse.length).toBeGreaterThan(0); expect(fullResponse.length).toBeGreaterThan(0);
@@ -2218,7 +2216,7 @@ describe("daemon E2E", () => {
for (const pattern of garbledPatterns) { for (const pattern of garbledPatterns) {
const match = fullResponse.match(pattern); const match = fullResponse.match(pattern);
if (match) { if (match) {
console.log("Found potential garbled text:", match[0]);
} }
// Note: We log but don't fail on these patterns as they might occur in valid text // Note: We log but don't fail on these patterns as they might occur in valid text
// The real test is whether the response is semantically coherent // The real test is whether the response is semantically coherent
@@ -2266,7 +2264,7 @@ describe("daemon E2E", () => {
expect(agent.provider).toBe("claude"); expect(agent.provider).toBe("claude");
// === MESSAGE 1: Establish conversation context === // === MESSAGE 1: Establish conversation context ===
console.log("[LONG-RUNNING TEST] Sending message 1...");
await ctx.client.sendMessage( await ctx.client.sendMessage(
agent.id, agent.id,
"Remember the number 42. Just confirm you remember it." "Remember the number 42. Just confirm you remember it."
@@ -2275,11 +2273,10 @@ describe("daemon E2E", () => {
let state = await ctx.client.waitForAgentIdle(agent.id, 120000); let state = await ctx.client.waitForAgentIdle(agent.id, 120000);
expect(state.status).toBe("idle"); expect(state.status).toBe("idle");
expect(state.lastError).toBeUndefined(); expect(state.lastError).toBeUndefined();
console.log("[LONG-RUNNING TEST] Message 1 complete");
// === MESSAGE 2: Build on conversation === // === MESSAGE 2: Build on conversation ===
ctx.client.clearMessageQueue(); // Clear queue to isolate message 2 ctx.client.clearMessageQueue(); // Clear queue to isolate message 2
console.log("[LONG-RUNNING TEST] Sending message 2...");
await ctx.client.sendMessage( await ctx.client.sendMessage(
agent.id, agent.id,
"Now remember the word 'elephant'. Just confirm you remember both the number and the word." "Now remember the word 'elephant'. Just confirm you remember both the number and the word."
@@ -2288,12 +2285,11 @@ describe("daemon E2E", () => {
state = await ctx.client.waitForAgentIdle(agent.id, 120000); state = await ctx.client.waitForAgentIdle(agent.id, 120000);
expect(state.status).toBe("idle"); expect(state.status).toBe("idle");
expect(state.lastError).toBeUndefined(); expect(state.lastError).toBeUndefined();
console.log("[LONG-RUNNING TEST] Message 2 complete");
// === MESSAGE 3: This is where the bug was reported to manifest === // === MESSAGE 3: This is where the bug was reported to manifest ===
// Clear queue so we can capture streaming chunks for message 3 only // Clear queue so we can capture streaming chunks for message 3 only
ctx.client.clearMessageQueue(); ctx.client.clearMessageQueue();
console.log("[LONG-RUNNING TEST] Sending message 3 (testing streaming integrity)...");
await ctx.client.sendMessage( await ctx.client.sendMessage(
agent.id, agent.id,
"Write a complete sentence using both the number (42) and the word (elephant) you remembered. The sentence should be grammatically correct English." "Write a complete sentence using both the number (42) and the word (elephant) you remembered. The sentence should be grammatically correct English."
@@ -2302,7 +2298,6 @@ describe("daemon E2E", () => {
state = await ctx.client.waitForAgentIdle(agent.id, 120000); state = await ctx.client.waitForAgentIdle(agent.id, 120000);
expect(state.status).toBe("idle"); expect(state.status).toBe("idle");
expect(state.lastError).toBeUndefined(); expect(state.lastError).toBeUndefined();
console.log("[LONG-RUNNING TEST] Message 3 complete");
// Collect all assistant_message timeline events from message 3 // Collect all assistant_message timeline events from message 3
const queue = ctx.client.getMessageQueue(); const queue = ctx.client.getMessageQueue();
@@ -2321,18 +2316,15 @@ describe("daemon E2E", () => {
} }
} }
console.log("[LONG-RUNNING TEST] Collected", assistantChunks.length, "chunks");
// Should have received at least one assistant message chunk // Should have received at least one assistant message chunk
expect(assistantChunks.length).toBeGreaterThan(0); expect(assistantChunks.length).toBeGreaterThan(0);
// Concatenate all chunks to form the complete response // Concatenate all chunks to form the complete response
const fullResponse = assistantChunks.join(""); const fullResponse = assistantChunks.join("");
console.log("[LONG-RUNNING TEST] Full response:", JSON.stringify(fullResponse));
console.log("[LONG-RUNNING TEST] Chunks:");
for (let i = 0; i < assistantChunks.length; i++) { for (let i = 0; i < assistantChunks.length; i++) {
console.log(` [${i}]: ${JSON.stringify(assistantChunks[i])}`);
} }
// CRITICAL ASSERTION 1: Response should contain expected content // CRITICAL ASSERTION 1: Response should contain expected content
@@ -2340,8 +2332,6 @@ describe("daemon E2E", () => {
const containsNumber = lowerResponse.includes("42"); const containsNumber = lowerResponse.includes("42");
const containsWord = lowerResponse.includes("elephant"); const containsWord = lowerResponse.includes("elephant");
console.log("[LONG-RUNNING TEST] Contains '42':", containsNumber);
console.log("[LONG-RUNNING TEST] Contains 'elephant':", containsWord);
expect(containsNumber).toBe(true); expect(containsNumber).toBe(true);
expect(containsWord).toBe(true); expect(containsWord).toBe(true);
@@ -2363,7 +2353,7 @@ describe("daemon E2E", () => {
if (currentEndsWithLetter && nextStartsWithLetter) { if (currentEndsWithLetter && nextStartsWithLetter) {
// This could be legitimate (word continues) or a split issue // This could be legitimate (word continues) or a split issue
// Log for debugging // Log for debugging
console.log(`[LONG-RUNNING TEST] Adjacent letter chunks: "${current.slice(-10)}" + "${next.slice(0, 10)}"`);
} }
} }
@@ -2382,7 +2372,7 @@ describe("daemon E2E", () => {
// Check for improperly concatenated words (very long "words" that shouldn't exist) // Check for improperly concatenated words (very long "words" that shouldn't exist)
const suspiciouslyLongWords = words.filter(w => w.length > 20); const suspiciouslyLongWords = words.filter(w => w.length > 20);
if (suspiciouslyLongWords.length > 0) { if (suspiciouslyLongWords.length > 0) {
console.log("[LONG-RUNNING TEST] Suspiciously long words:", suspiciouslyLongWords);
} }
// Allow some technical words but flag excessive length // Allow some technical words but flag excessive length
expect(suspiciouslyLongWords.filter(w => w.length > 30).length).toBe(0); expect(suspiciouslyLongWords.filter(w => w.length > 30).length).toBe(0);
@@ -2415,7 +2405,6 @@ describe("daemon E2E", () => {
// === STEP 1: Run external codex exec with a memorable number === // === STEP 1: Run external codex exec with a memorable number ===
// We use spawn so we can send input and capture output // We use spawn so we can send input and capture output
console.log("[EXTERNAL SESSION TEST] Spawning external codex exec...");
// Use a memorable number that we'll ask about later // Use a memorable number that we'll ask about later
const magicNumber = 69; const magicNumber = 69;
@@ -2445,32 +2434,30 @@ describe("daemon E2E", () => {
codexProcess.stdout.on("data", (data: Buffer) => { codexProcess.stdout.on("data", (data: Buffer) => {
const text = data.toString(); const text = data.toString();
codexOutput += text; codexOutput += text;
console.log("[EXTERNAL SESSION TEST] stdout:", text);
// Look for session ID in output // Look for session ID in output
// Format: "session id: 019b5ea3-25d5-7202-bd06-6b1db405e505" // Format: "session id: 019b5ea3-25d5-7202-bd06-6b1db405e505"
const match = text.match(/session id:\s*([0-9a-f-]+)/i); const match = text.match(/session id:\s*([0-9a-f-]+)/i);
if (match) { if (match) {
sessionId = match[1]; sessionId = match[1];
console.log("[EXTERNAL SESSION TEST] Captured session ID:", sessionId);
} }
}); });
codexProcess.stderr.on("data", (data: Buffer) => { codexProcess.stderr.on("data", (data: Buffer) => {
const text = data.toString(); const text = data.toString();
console.log("[EXTERNAL SESSION TEST] stderr:", text);
// Session ID might also appear in stderr // Session ID might also appear in stderr
const match = text.match(/session id:\s*([0-9a-f-]+)/i); const match = text.match(/session id:\s*([0-9a-f-]+)/i);
if (match && !sessionId) { if (match && !sessionId) {
sessionId = match[1]; sessionId = match[1];
console.log("[EXTERNAL SESSION TEST] Captured session ID from stderr:", sessionId);
} }
}); });
codexProcess.on("close", (code) => { codexProcess.on("close", (code) => {
clearTimeout(timeout); clearTimeout(timeout);
console.log("[EXTERNAL SESSION TEST] codex exec exited with code:", code);
if (code === 0 || sessionId) { if (code === 0 || sessionId) {
resolve(); resolve();
} else { } else {
@@ -2484,12 +2471,9 @@ describe("daemon E2E", () => {
}); });
}); });
console.log("[EXTERNAL SESSION TEST] Full output:", codexOutput);
// Verify we captured the session ID // Verify we captured the session ID
expect(sessionId).not.toBeNull(); expect(sessionId).not.toBeNull();
expect(sessionId).toMatch(/^[0-9a-f-]+$/); expect(sessionId).toMatch(/^[0-9a-f-]+$/);
console.log("[EXTERNAL SESSION TEST] Session ID:", sessionId);
// === STEP 2: Find the transcript file for this session === // === STEP 2: Find the transcript file for this session ===
// Codex stores transcripts at ~/.codex/sessions/**/*-{sessionId}.jsonl // Codex stores transcripts at ~/.codex/sessions/**/*-{sessionId}.jsonl
@@ -2497,8 +2481,6 @@ describe("daemon E2E", () => {
const actualCodexHome = path.join(process.env.HOME || "", ".codex"); const actualCodexHome = path.join(process.env.HOME || "", ".codex");
const sessionsDir = path.join(actualCodexHome, "sessions"); const sessionsDir = path.join(actualCodexHome, "sessions");
console.log("[EXTERNAL SESSION TEST] Looking for transcript in:", sessionsDir);
// Find the transcript file // Find the transcript file
function findTranscriptFile(dir: string, targetSessionId: string): string | null { function findTranscriptFile(dir: string, targetSessionId: string): string | null {
try { try {
@@ -2519,7 +2501,6 @@ describe("daemon E2E", () => {
} }
const transcriptFile = findTranscriptFile(sessionsDir, sessionId!); const transcriptFile = findTranscriptFile(sessionsDir, sessionId!);
console.log("[EXTERNAL SESSION TEST] Found transcript file:", transcriptFile);
// Verify transcript file exists // Verify transcript file exists
expect(transcriptFile).not.toBeNull(); expect(transcriptFile).not.toBeNull();
@@ -2527,11 +2508,10 @@ describe("daemon E2E", () => {
// Read and verify transcript has content // Read and verify transcript has content
const transcriptContent = readFileSync(transcriptFile!, "utf-8"); const transcriptContent = readFileSync(transcriptFile!, "utf-8");
console.log("[EXTERNAL SESSION TEST] Transcript size:", transcriptContent.length, "bytes");
expect(transcriptContent.length).toBeGreaterThan(0); expect(transcriptContent.length).toBeGreaterThan(0);
// === STEP 3: Import this session into the daemon === // === STEP 3: Import this session into the daemon ===
console.log("[EXTERNAL SESSION TEST] Creating daemon agent with experimental_resume...");
const agent = await ctx.client.createAgent({ const agent = await ctx.client.createAgent({
provider: "codex", provider: "codex",
@@ -2547,10 +2527,9 @@ describe("daemon E2E", () => {
expect(agent.id).toBeTruthy(); expect(agent.id).toBeTruthy();
expect(agent.status).toBe("idle"); expect(agent.status).toBe("idle");
console.log("[EXTERNAL SESSION TEST] Created agent:", agent.id);
// === STEP 4: Ask the daemon agent about the number === // === STEP 4: Ask the daemon agent about the number ===
console.log("[EXTERNAL SESSION TEST] Asking about the remembered number...");
ctx.client.clearMessageQueue(); ctx.client.clearMessageQueue();
await ctx.client.sendMessage( await ctx.client.sendMessage(
@@ -2581,7 +2560,6 @@ describe("daemon E2E", () => {
} }
const fullResponse = assistantMessages.join(""); const fullResponse = assistantMessages.join("");
console.log("[EXTERNAL SESSION TEST] Agent response:", JSON.stringify(fullResponse));
// CRITICAL ASSERTION: The response should contain the magic number // CRITICAL ASSERTION: The response should contain the magic number
// This proves the daemon agent successfully loaded the external session's context // This proves the daemon agent successfully loaded the external session's context
@@ -2793,7 +2771,7 @@ describe("daemon E2E", () => {
const magicNumber = 69; const magicNumber = 69;
// === STEP 1: Create Claude agent and have it remember a number === // === STEP 1: Create Claude agent and have it remember a number ===
console.log("[CLAUDE PERSISTENCE TEST] Creating Claude agent...");
const agent = await ctx.client.createAgent({ const agent = await ctx.client.createAgent({
provider: "claude", provider: "claude",
cwd, cwd,
@@ -2804,10 +2782,9 @@ describe("daemon E2E", () => {
expect(agent.id).toBeTruthy(); expect(agent.id).toBeTruthy();
expect(agent.status).toBe("idle"); expect(agent.status).toBe("idle");
expect(agent.provider).toBe("claude"); expect(agent.provider).toBe("claude");
console.log("[CLAUDE PERSISTENCE TEST] Created agent:", agent.id);
// === STEP 2: Ask it to remember the number === // === STEP 2: Ask it to remember the number ===
console.log("[CLAUDE PERSISTENCE TEST] Asking to remember number...");
await ctx.client.sendMessage( await ctx.client.sendMessage(
agent.id, agent.id,
`Remember this number: ${magicNumber}. Just confirm you've remembered it and reply with a single short sentence.` `Remember this number: ${magicNumber}. Just confirm you've remembered it and reply with a single short sentence.`
@@ -2833,7 +2810,7 @@ describe("daemon E2E", () => {
} }
} }
const confirmationResponse = confirmationMessages.join(""); const confirmationResponse = confirmationMessages.join("");
console.log("[CLAUDE PERSISTENCE TEST] Confirmation response:", JSON.stringify(confirmationResponse));
expect(confirmationResponse.length).toBeGreaterThan(0); expect(confirmationResponse.length).toBeGreaterThan(0);
// === STEP 3: Get persistence handle and delete agent === // === STEP 3: Get persistence handle and delete agent ===
@@ -2841,24 +2818,21 @@ describe("daemon E2E", () => {
const persistence = afterRemember.persistence; const persistence = afterRemember.persistence;
expect(persistence?.provider).toBe("claude"); expect(persistence?.provider).toBe("claude");
expect(persistence?.sessionId).toBeTruthy(); expect(persistence?.sessionId).toBeTruthy();
console.log("[CLAUDE PERSISTENCE TEST] Got persistence handle:", persistence?.sessionId);
// Delete the agent // Delete the agent
await ctx.client.deleteAgent(agent.id); await ctx.client.deleteAgent(agent.id);
console.log("[CLAUDE PERSISTENCE TEST] Deleted agent");
// === STEP 4: Resume the agent using persistence handle === // === STEP 4: Resume the agent using persistence handle ===
console.log("[CLAUDE PERSISTENCE TEST] Resuming agent...");
ctx.client.clearMessageQueue(); ctx.client.clearMessageQueue();
const resumedAgent = await ctx.client.resumeAgent(persistence!); const resumedAgent = await ctx.client.resumeAgent(persistence!);
expect(resumedAgent.id).toBeTruthy(); expect(resumedAgent.id).toBeTruthy();
expect(resumedAgent.status).toBe("idle"); expect(resumedAgent.status).toBe("idle");
expect(resumedAgent.provider).toBe("claude"); expect(resumedAgent.provider).toBe("claude");
console.log("[CLAUDE PERSISTENCE TEST] Resumed agent:", resumedAgent.id);
// === STEP 5: Ask about the remembered number === // === STEP 5: Ask about the remembered number ===
console.log("[CLAUDE PERSISTENCE TEST] Asking about remembered number...");
ctx.client.clearMessageQueue(); ctx.client.clearMessageQueue();
await ctx.client.sendMessage( await ctx.client.sendMessage(
resumedAgent.id, resumedAgent.id,
@@ -2885,7 +2859,6 @@ describe("daemon E2E", () => {
} }
} }
const fullResponse = recallMessages.join(""); const fullResponse = recallMessages.join("");
console.log("[CLAUDE PERSISTENCE TEST] Recall response:", JSON.stringify(fullResponse));
// CRITICAL ASSERTION: The response should contain the magic number // CRITICAL ASSERTION: The response should contain the magic number
// This proves the Claude agent successfully preserved conversation context // This proves the Claude agent successfully preserved conversation context
@@ -2917,7 +2890,6 @@ describe("daemon E2E", () => {
expect(agent.provider).toBe("claude"); expect(agent.provider).toBe("claude");
// === MESSAGE 1: Start a long-running prompt that will be interrupted === // === MESSAGE 1: Start a long-running prompt that will be interrupted ===
console.log("[RACE CONDITION TEST] Sending message 1 (will be interrupted)...");
// Record queue position BEFORE message 1 to find the cutoff point later // Record queue position BEFORE message 1 to find the cutoff point later
const msg1StartPosition = ctx.client.getMessageQueue().length; const msg1StartPosition = ctx.client.getMessageQueue().length;
@@ -2935,11 +2907,9 @@ describe("daemon E2E", () => {
// === MESSAGE 2: Immediately send another message to interrupt === // === MESSAGE 2: Immediately send another message to interrupt ===
// This triggers the race condition where Turn 2's forwardPromptEvents // This triggers the race condition where Turn 2's forwardPromptEvents
// resets streamedAssistantTextThisTurn while Turn 1 is still reading it // resets streamedAssistantTextThisTurn while Turn 1 is still reading it
console.log("[RACE CONDITION TEST] Sending message 2 (interrupting turn 1)...");
// Record queue position BEFORE message 2 to find message 2 chunks // Record queue position BEFORE message 2 to find message 2 chunks
const msg2StartPosition = ctx.client.getMessageQueue().length; const msg2StartPosition = ctx.client.getMessageQueue().length;
console.log("[RACE CONDITION TEST] Queue position before msg2:", msg2StartPosition);
await ctx.client.sendMessage( await ctx.client.sendMessage(
agent.id, agent.id,
@@ -2948,7 +2918,7 @@ describe("daemon E2E", () => {
// Wait for Turn 2 to complete - use a manual polling approach // Wait for Turn 2 to complete - use a manual polling approach
// We need to wait for: running -> idle (after msg2's user_message) // We need to wait for: running -> idle (after msg2's user_message)
console.log("[RACE CONDITION TEST] Waiting for agent to become idle after msg2...");
const maxWaitMs = 120000; const maxWaitMs = 120000;
const pollIntervalMs = 500; const pollIntervalMs = 500;
const startTime = Date.now(); const startTime = Date.now();
@@ -2987,7 +2957,7 @@ describe("daemon E2E", () => {
} }
if (sawIdleAfterRunning) { if (sawIdleAfterRunning) {
console.log("[RACE CONDITION TEST] Agent became idle/error after msg2:", lastState?.status);
break; break;
} }
await new Promise(resolve => setTimeout(resolve, pollIntervalMs)); await new Promise(resolve => setTimeout(resolve, pollIntervalMs));
@@ -2996,26 +2966,25 @@ describe("daemon E2E", () => {
expect(lastState).not.toBeNull(); expect(lastState).not.toBeNull();
expect(lastState!.status).toBe("idle"); expect(lastState!.status).toBe("idle");
expect(lastState!.lastError).toBeUndefined(); expect(lastState!.lastError).toBeUndefined();
console.log("[RACE CONDITION TEST] Message 2 complete");
// Collect assistant_message chunks from message 2 only (after msg2StartPosition) // Collect assistant_message chunks from message 2 only (after msg2StartPosition)
const queue = ctx.client.getMessageQueue(); const queue = ctx.client.getMessageQueue();
const assistantChunks: string[] = []; const assistantChunks: string[] = [];
// Debug: dump all events from queue // Debug: dump all events from queue
console.log("[RACE CONDITION TEST] Full queue dump (all events):");
for (let i = 0; i < queue.length; i++) { for (let i = 0; i < queue.length; i++) {
const m = queue[i]; const m = queue[i];
if (m.type === "agent_stream" && m.payload.agentId === agent.id) { if (m.type === "agent_stream" && m.payload.agentId === agent.id) {
const event = m.payload.event; const event = m.payload.event;
if (event.type === "timeline") { if (event.type === "timeline") {
const item = event.item; const item = event.item;
console.log(` [${i}] (${i >= msg2StartPosition ? "msg2" : "msg1"}): timeline/${item.type}`, item.type === "assistant_message" || item.type === "user_message" ? JSON.stringify((item as any).text?.substring(0, 50)) : "");
} else { } else {
console.log(` [${i}] (${i >= msg2StartPosition ? "msg2" : "msg1"}): ${event.type}`, (event as any).error || "");
} }
} else if (m.type === "agent_state" && m.payload.id === agent.id) { } else if (m.type === "agent_state" && m.payload.id === agent.id) {
console.log(` [${i}] (${i >= msg2StartPosition ? "msg2" : "msg1"}): agent_state -> ${m.payload.status}`, m.payload.lastError || "");
} }
} }
@@ -3034,7 +3003,7 @@ describe("daemon E2E", () => {
const item = m.payload.event.item; const item = m.payload.event.item;
if (item.type === "user_message" && (item.text as string)?.includes("Hello world")) { if (item.type === "user_message" && (item.text as string)?.includes("Hello world")) {
foundMsg2UserMessage = true; foundMsg2UserMessage = true;
console.log("[RACE CONDITION TEST] Found message 2 user prompt");
} }
// Collect assistant messages after we found the user message // Collect assistant messages after we found the user message
if (foundMsg2UserMessage && item.type === "assistant_message" && item.text) { if (foundMsg2UserMessage && item.type === "assistant_message" && item.text) {
@@ -3043,10 +3012,9 @@ describe("daemon E2E", () => {
} }
} }
console.log("[RACE CONDITION TEST] Collected", assistantChunks.length, "chunks");
console.log("[RACE CONDITION TEST] Chunks:");
for (let i = 0; i < assistantChunks.length; i++) { for (let i = 0; i < assistantChunks.length; i++) {
console.log(` [${i}]: ${JSON.stringify(assistantChunks[i])}`);
} }
// Should have received at least one assistant message chunk // Should have received at least one assistant message chunk
@@ -3054,7 +3022,6 @@ describe("daemon E2E", () => {
// Concatenate all chunks // Concatenate all chunks
const fullResponse = assistantChunks.join(""); const fullResponse = assistantChunks.join("");
console.log("[RACE CONDITION TEST] Full response:", JSON.stringify(fullResponse));
// CRITICAL ASSERTION: Response should contain coherent text // CRITICAL ASSERTION: Response should contain coherent text
// If there's a race condition with flag corruption, we might get: // If there's a race condition with flag corruption, we might get:
@@ -3065,7 +3032,7 @@ describe("daemon E2E", () => {
// Check for basic coherence - should have recognizable words // Check for basic coherence - should have recognizable words
const wordPattern = /\b[a-zA-Z]+\b/g; const wordPattern = /\b[a-zA-Z]+\b/g;
const words = fullResponse.match(wordPattern) || []; const words = fullResponse.match(wordPattern) || [];
console.log("[RACE CONDITION TEST] Words found:", words.length);
expect(words.length).toBeGreaterThan(0); expect(words.length).toBeGreaterThan(0);
// Check for UTF-8 corruption // Check for UTF-8 corruption
@@ -3077,7 +3044,7 @@ describe("daemon E2E", () => {
// Check for suspiciously long "words" that indicate missing spaces/garbling // Check for suspiciously long "words" that indicate missing spaces/garbling
const suspiciouslyLongWords = words.filter(w => w.length > 30); const suspiciouslyLongWords = words.filter(w => w.length > 30);
if (suspiciouslyLongWords.length > 0) { if (suspiciouslyLongWords.length > 0) {
console.log("[RACE CONDITION TEST] Suspiciously long words:", suspiciouslyLongWords);
} }
expect(suspiciouslyLongWords.length).toBe(0); expect(suspiciouslyLongWords.length).toBe(0);
@@ -3093,8 +3060,8 @@ describe("daemon E2E", () => {
lowerResponse.includes("babbage"); lowerResponse.includes("babbage");
if (containsComputingContent) { if (containsComputingContent) {
console.log("[RACE CONDITION TEST] ERROR: Response contains content from message 1!");
console.log("[RACE CONDITION TEST] This indicates the race condition: message 2 was sent but message 1's response was returned");
} }
// This MUST fail if we got message 1's response instead of message 2's // This MUST fail if we got message 1's response instead of message 2's
expect(containsComputingContent).toBe(false); expect(containsComputingContent).toBe(false);
@@ -3121,7 +3088,7 @@ describe("daemon E2E", () => {
expect(agent.id).toBeTruthy(); expect(agent.id).toBeTruthy();
// Start a long-running tool call (sleep command) // Start a long-running tool call (sleep command)
console.log("[TOOL INTERRUPT TEST] Sending message 1 with long sleep command...");
const msg1StartPosition = ctx.client.getMessageQueue().length; const msg1StartPosition = ctx.client.getMessageQueue().length;
await ctx.client.sendMessage( await ctx.client.sendMessage(
@@ -3130,7 +3097,7 @@ describe("daemon E2E", () => {
); );
// Wait for the tool call to start (agent should be running and we should see the bash tool) // Wait for the tool call to start (agent should be running and we should see the bash tool)
console.log("[TOOL INTERRUPT TEST] Waiting for tool call to start...");
let sawToolCall = false; let sawToolCall = false;
const toolWaitStart = Date.now(); const toolWaitStart = Date.now();
while (Date.now() - toolWaitStart < 30000) { while (Date.now() - toolWaitStart < 30000) {
@@ -3146,7 +3113,7 @@ describe("daemon E2E", () => {
const tc = m.payload.event.item; const tc = m.payload.event.item;
if (tc.name?.toLowerCase().includes("bash") || tc.name?.toLowerCase().includes("shell")) { if (tc.name?.toLowerCase().includes("bash") || tc.name?.toLowerCase().includes("shell")) {
sawToolCall = true; sawToolCall = true;
console.log("[TOOL INTERRUPT TEST] Tool call started:", tc.name);
break; break;
} }
} }
@@ -3158,7 +3125,7 @@ describe("daemon E2E", () => {
expect(sawToolCall).toBe(true); expect(sawToolCall).toBe(true);
// Now send an interrupting message while the tool is running // Now send an interrupting message while the tool is running
console.log("[TOOL INTERRUPT TEST] Sending message 2 to interrupt...");
const msg2StartPosition = ctx.client.getMessageQueue().length; const msg2StartPosition = ctx.client.getMessageQueue().length;
await ctx.client.sendMessage( await ctx.client.sendMessage(
@@ -3167,7 +3134,7 @@ describe("daemon E2E", () => {
); );
// Track state transitions // Track state transitions
console.log("[TOOL INTERRUPT TEST] Monitoring state transitions...");
const stateTransitions: Array<{ status: string; timestamp: number; lastError?: string }> = []; const stateTransitions: Array<{ status: string; timestamp: number; lastError?: string }> = [];
const monitorStart = Date.now(); const monitorStart = Date.now();
@@ -3183,7 +3150,7 @@ describe("daemon E2E", () => {
timestamp: Date.now() - monitorStart, timestamp: Date.now() - monitorStart,
lastError: m.payload.lastError, lastError: m.payload.lastError,
}); });
console.log(`[TOOL INTERRUPT TEST] State: ${m.payload.status} at ${Date.now() - monitorStart}ms`, m.payload.lastError || "");
} }
} }
} }
@@ -3198,14 +3165,11 @@ describe("daemon E2E", () => {
await new Promise(r => setTimeout(r, 200)); await new Promise(r => setTimeout(r, 200));
} }
console.log("[TOOL INTERRUPT TEST] State transitions:", JSON.stringify(stateTransitions, null, 2));
// Verify we got proper state transitions // Verify we got proper state transitions
expect(stateTransitions.length).toBeGreaterThan(0); expect(stateTransitions.length).toBeGreaterThan(0);
// Check if we ended in idle (success) or error // Check if we ended in idle (success) or error
const finalState = stateTransitions[stateTransitions.length - 1]; const finalState = stateTransitions[stateTransitions.length - 1];
console.log("[TOOL INTERRUPT TEST] Final state:", finalState);
// Look for the response to message 2 // Look for the response to message 2
const queue = ctx.client.getMessageQueue(); const queue = ctx.client.getMessageQueue();
@@ -3229,8 +3193,6 @@ describe("daemon E2E", () => {
} }
} }
console.log("[TOOL INTERRUPT TEST] Found user message 2:", foundMsg2User);
console.log("[TOOL INTERRUPT TEST] Assistant messages after msg2:", assistantMessages);
// The key assertion: agent should have responded to message 2 // The key assertion: agent should have responded to message 2
if (finalState.status === "idle") { if (finalState.status === "idle") {
@@ -3258,7 +3220,7 @@ describe("daemon E2E", () => {
expect(agent.id).toBeTruthy(); expect(agent.id).toBeTruthy();
// Send 3 messages in rapid succession without waiting // Send 3 messages in rapid succession without waiting
console.log("[RAPID MSG TEST] Sending 3 messages rapidly...");
const startPosition = ctx.client.getMessageQueue().length; const startPosition = ctx.client.getMessageQueue().length;
const msg1 = "Say: MESSAGE_ONE"; const msg1 = "Say: MESSAGE_ONE";
@@ -3285,32 +3247,30 @@ describe("daemon E2E", () => {
// Send all 3 messages // Send all 3 messages
await ctx.client.sendMessage(agent.id, msg1); await ctx.client.sendMessage(agent.id, msg1);
console.log("[RAPID MSG TEST] MSG1 sent, waiting briefly...");
await new Promise(r => setTimeout(r, 100)); await new Promise(r => setTimeout(r, 100));
await ctx.client.sendMessage(agent.id, msg2); await ctx.client.sendMessage(agent.id, msg2);
console.log("[RAPID MSG TEST] MSG2 sent, waiting briefly...");
await new Promise(r => setTimeout(r, 100)); await new Promise(r => setTimeout(r, 100));
await ctx.client.sendMessage(agent.id, msg3); await ctx.client.sendMessage(agent.id, msg3);
console.log("[RAPID MSG TEST] MSG3 sent");
// First, wait until all 3 user messages are recorded // First, wait until all 3 user messages are recorded
console.log("[RAPID MSG TEST] Waiting for all 3 user messages to be recorded...");
const userMsgWaitStart = Date.now(); const userMsgWaitStart = Date.now();
while (Date.now() - userMsgWaitStart < 30000) { while (Date.now() - userMsgWaitStart < 30000) {
const count = countUserMessages(); const count = countUserMessages();
console.log(`[RAPID MSG TEST] User message count: ${count}`);
if (count >= 3) break; if (count >= 3) break;
await new Promise(r => setTimeout(r, 200)); await new Promise(r => setTimeout(r, 200));
} }
const finalUserMsgCount = countUserMessages(); const finalUserMsgCount = countUserMessages();
console.log(`[RAPID MSG TEST] Final user message count: ${finalUserMsgCount}`);
// Now wait for agent to become idle after processing all 3 messages // Now wait for agent to become idle after processing all 3 messages
// We need to see at least 3 running transitions to know all messages were processed // We need to see at least 3 running transitions to know all messages were processed
console.log("[RAPID MSG TEST] Waiting for agent to finish processing all messages...");
const waitStart = Date.now(); const waitStart = Date.now();
let runningCount = 0; let runningCount = 0;
let finalState: AgentSnapshotPayload | null = null; let finalState: AgentSnapshotPayload | null = null;
@@ -3338,8 +3298,6 @@ describe("daemon E2E", () => {
await new Promise(r => setTimeout(r, 500)); await new Promise(r => setTimeout(r, 500));
} }
console.log("[RAPID MSG TEST] Final state:", finalState?.status, finalState?.lastError);
console.log("[RAPID MSG TEST] Total running transitions:", runningCount);
// Analyze what happened // Analyze what happened
const queue = ctx.client.getMessageQueue(); const queue = ctx.client.getMessageQueue();
@@ -3367,10 +3325,8 @@ describe("daemon E2E", () => {
} }
} }
console.log("[RAPID MSG TEST] User messages recorded:", userMessages.length, userMessages);
console.log("[RAPID MSG TEST] Assistant messages:", assistantMessages.length, JSON.stringify(assistantMessages));
console.log("[RAPID MSG TEST] State changes:", stateChanges.join(" -> "));
console.log("[RAPID MSG TEST] Total queue items since start:", queue.length - startPosition);
// All 3 user messages should have been recorded // All 3 user messages should have been recorded
expect(userMessages.length).toBe(3); expect(userMessages.length).toBe(3);
@@ -3380,7 +3336,6 @@ describe("daemon E2E", () => {
// The last turn should have completed successfully (not failed due to race condition) // The last turn should have completed successfully (not failed due to race condition)
const lastResponse = assistantMessages[assistantMessages.length - 1]?.toLowerCase() || ""; const lastResponse = assistantMessages[assistantMessages.length - 1]?.toLowerCase() || "";
console.log("[RAPID MSG TEST] Last response:", lastResponse);
// Verify we got a proper turn_completed event (not turn_failed from race condition) // Verify we got a proper turn_completed event (not turn_failed from race condition)
const turnCompletedEvents = queue.filter((m, i) => const turnCompletedEvents = queue.filter((m, i) =>
@@ -3395,8 +3350,7 @@ describe("daemon E2E", () => {
m.payload.agentId === agent.id && m.payload.agentId === agent.id &&
m.payload.event.type === "turn_failed" m.payload.event.type === "turn_failed"
); );
console.log("[RAPID MSG TEST] Turn completed events:", turnCompletedEvents.length);
console.log("[RAPID MSG TEST] Turn failed events:", turnFailedEvents.length);
// The final turn should complete successfully, not fail // The final turn should complete successfully, not fail
expect(turnCompletedEvents.length).toBeGreaterThan(0); expect(turnCompletedEvents.length).toBeGreaterThan(0);
@@ -3405,7 +3359,7 @@ describe("daemon E2E", () => {
// The response should mention "three" since that was the last message sent // The response should mention "three" since that was the last message sent
const combinedResponse = assistantMessages.join(" ").toLowerCase(); const combinedResponse = assistantMessages.join(" ").toLowerCase();
console.log("[RAPID MSG TEST] Combined response:", combinedResponse);
expect(combinedResponse).toContain("three"); expect(combinedResponse).toContain("three");
await ctx.client.deleteAgent(agent.id); await ctx.client.deleteAgent(agent.id);
@@ -3446,16 +3400,7 @@ describe("daemon E2E", () => {
// Helper to log tool call structure in a consistent format // Helper to log tool call structure in a consistent format
function logToolCall(prefix: string, tc: AgentTimelineItem): void { function logToolCall(prefix: string, tc: AgentTimelineItem): void {
if (tc.type !== "tool_call") return; if (tc.type !== "tool_call") return;
console.log(
`[${prefix}]`,
JSON.stringify({
name: tc.name,
callId: tc.callId,
status: tc.status,
hasInput: tc.input !== undefined,
hasOutput: tc.output !== undefined,
})
);
} }
test( test(
+15 -7
View File
@@ -7,30 +7,34 @@ dotenv.config({ path: path.resolve(__dirname, "../../.env") });
import { createPaseoDaemon } from "./bootstrap.js"; import { createPaseoDaemon } from "./bootstrap.js";
import { loadConfig } from "./config.js"; import { loadConfig } from "./config.js";
import { resolvePaseoHome } from "./paseo-home.js"; import { resolvePaseoHome } from "./paseo-home.js";
import { createRootLogger } from "./logger.js";
import { loadPersistedConfig } from "./persisted-config.js";
async function main() { async function main() {
const paseoHome = resolvePaseoHome(); const paseoHome = resolvePaseoHome();
const persistedConfig = loadPersistedConfig(paseoHome);
const logger = createRootLogger(persistedConfig);
const config = loadConfig(paseoHome); const config = loadConfig(paseoHome);
const daemon = await createPaseoDaemon(config); const daemon = await createPaseoDaemon(config);
await daemon.start(); await daemon.start();
const handleShutdown = async (signal: string) => { const handleShutdown = async (signal: string) => {
console.log(`\n${signal} received, shutting down gracefully...`); logger.info(`${signal} received, shutting down gracefully...`);
const forceExit = setTimeout(() => { const forceExit = setTimeout(() => {
console.log("Forcing shutdown - HTTP server didn't close in time"); logger.warn("Forcing shutdown - HTTP server didn't close in time");
process.exit(1); process.exit(1);
}, 10000); }, 10000);
try { try {
await daemon.stop(); await daemon.stop();
clearTimeout(forceExit); clearTimeout(forceExit);
console.log("Server closed"); logger.info("Server closed");
process.exit(0); process.exit(0);
} catch (error) { } catch (err) {
clearTimeout(forceExit); clearTimeout(forceExit);
console.error("Shutdown failed:", error); logger.error({ err }, "Shutdown failed");
process.exit(1); process.exit(1);
} }
}; };
@@ -39,7 +43,11 @@ async function main() {
process.on("SIGINT", () => handleShutdown("SIGINT")); process.on("SIGINT", () => handleShutdown("SIGINT"));
} }
main().catch((error) => { main().catch((err) => {
console.error("Failed to start server:", error); // Logger might not be initialized yet, so we need to handle this specially
const paseoHome = resolvePaseoHome();
const persistedConfig = loadPersistedConfig(paseoHome);
const logger = createRootLogger(persistedConfig);
logger.error({ err }, "Failed to start server");
process.exit(1); process.exit(1);
}); });
+109
View File
@@ -0,0 +1,109 @@
import { describe, it, expect, beforeEach, afterEach } from "vitest";
import { resolveLogConfig } from "./logger.js";
import type { PersistedConfig } from "./persisted-config.js";
describe("resolveLogConfig", () => {
const originalEnv = process.env;
beforeEach(() => {
process.env = { ...originalEnv };
delete process.env.PASEO_LOG;
delete process.env.PASEO_LOG_FORMAT;
});
afterEach(() => {
process.env = originalEnv;
});
it("returns defaults when no config or env vars", () => {
const result = resolveLogConfig(undefined);
expect(result).toEqual({ level: "info", format: "pretty" });
});
it("uses config.json values over defaults", () => {
const config: PersistedConfig = {
log: {
level: "debug",
format: "json",
},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "debug", format: "json" });
});
it("uses env PASEO_LOG over config.json level", () => {
process.env.PASEO_LOG = "warn";
const config: PersistedConfig = {
log: {
level: "debug",
format: "json",
},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "warn", format: "json" });
});
it("uses env PASEO_LOG_FORMAT over config.json format", () => {
process.env.PASEO_LOG_FORMAT = "pretty";
const config: PersistedConfig = {
log: {
level: "debug",
format: "json",
},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "debug", format: "pretty" });
});
it("env vars override both config.json and defaults", () => {
process.env.PASEO_LOG = "error";
process.env.PASEO_LOG_FORMAT = "json";
const config: PersistedConfig = {
log: {
level: "info",
format: "pretty",
},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "error", format: "json" });
});
it("handles partial config - level only", () => {
const config: PersistedConfig = {
log: {
level: "warn",
},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "warn", format: "pretty" });
});
it("handles partial config - format only", () => {
const config: PersistedConfig = {
log: {
format: "json",
},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "info", format: "json" });
});
it("handles empty log object in config", () => {
const config: PersistedConfig = {
log: {},
};
const result = resolveLogConfig(config);
expect(result).toEqual({ level: "info", format: "pretty" });
});
it("supports all log levels", () => {
const levels: Array<"trace" | "debug" | "info" | "warn" | "error" | "fatal"> =
["trace", "debug", "info", "warn", "error", "fatal"];
for (const level of levels) {
process.env.PASEO_LOG = level;
const result = resolveLogConfig(undefined);
expect(result.level).toBe(level);
}
});
});
+62
View File
@@ -0,0 +1,62 @@
import pino from "pino";
import type { PersistedConfig } from "./persisted-config.js";
export type LogLevel = "trace" | "debug" | "info" | "warn" | "error" | "fatal";
export type LogFormat = "pretty" | "json";
export interface ResolvedLogConfig {
level: LogLevel;
format: LogFormat;
}
export function resolveLogConfig(
persistedConfig: PersistedConfig | undefined
): ResolvedLogConfig {
const envLevel = process.env.PASEO_LOG as LogLevel | undefined;
const envFormat = process.env.PASEO_LOG_FORMAT as LogFormat | undefined;
const level: LogLevel =
envLevel ?? persistedConfig?.log?.level ?? "info";
const format: LogFormat =
envFormat ?? persistedConfig?.log?.format ?? "pretty";
return { level, format };
}
let rootLogger: pino.Logger | undefined;
export function createRootLogger(
persistedConfig: PersistedConfig | undefined
): pino.Logger {
const config = resolveLogConfig(persistedConfig);
const transport =
config.format === "pretty"
? {
target: "pino-pretty",
options: {
colorize: true,
singleLine: true,
ignore: "pid,hostname",
},
}
: undefined;
rootLogger = pino({
level: config.level,
transport,
});
return rootLogger;
}
export function getRootLogger(): pino.Logger {
if (!rootLogger) {
throw new Error("Root logger not initialized. Call createRootLogger first.");
}
return rootLogger;
}
export function createChildLogger(name: string): pino.Logger {
return getRootLogger().child({ name });
}
+23 -3
View File
@@ -1,6 +1,7 @@
import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { existsSync, readFileSync, writeFileSync } from "node:fs";
import path from "node:path"; import path from "node:path";
import { z } from "zod"; import { z } from "zod";
import { getRootLogger } from "./logger.js";
const PersistedConfigSchema = z.object({ const PersistedConfigSchema = z.object({
listen: z.string().optional(), listen: z.string().optional(),
@@ -9,6 +10,14 @@ const PersistedConfigSchema = z.object({
allowedOrigins: z.array(z.string()).default([]), allowedOrigins: z.array(z.string()).default([]),
}) })
.default({}), .default({}),
log: z
.object({
level: z
.enum(["trace", "debug", "info", "warn", "error", "fatal"])
.optional(),
format: z.enum(["pretty", "json"]).optional(),
})
.optional(),
}); });
export type PersistedConfig = z.infer<typeof PersistedConfigSchema>; export type PersistedConfig = z.infer<typeof PersistedConfigSchema>;
@@ -19,11 +28,21 @@ function getConfigPath(paseoHome: string): string {
return path.join(paseoHome, CONFIG_FILENAME); return path.join(paseoHome, CONFIG_FILENAME);
} }
function getLogger() {
try {
return getRootLogger().child({ module: "config" });
} catch {
// Root logger not initialized yet, return null
return null;
}
}
export function loadPersistedConfig(paseoHome: string): PersistedConfig { export function loadPersistedConfig(paseoHome: string): PersistedConfig {
const logger = getLogger();
const configPath = getConfigPath(paseoHome); const configPath = getConfigPath(paseoHome);
if (!existsSync(configPath)) { if (!existsSync(configPath)) {
console.log(`[Config] No config file at ${configPath}, using defaults`); logger?.info(`No config file at ${configPath}, using defaults`);
return PersistedConfigSchema.parse({}); return PersistedConfigSchema.parse({});
} }
@@ -51,7 +70,7 @@ export function loadPersistedConfig(paseoHome: string): PersistedConfig {
throw new Error(`[Config] Invalid config in ${configPath}:\n${issues}`); throw new Error(`[Config] Invalid config in ${configPath}:\n${issues}`);
} }
console.log(`[Config] Loaded from ${configPath}`); logger?.info(`Loaded from ${configPath}`);
return result.data; return result.data;
} }
@@ -59,6 +78,7 @@ export function savePersistedConfig(
paseoHome: string, paseoHome: string,
config: PersistedConfig config: PersistedConfig
): void { ): void {
const logger = getLogger();
const configPath = getConfigPath(paseoHome); const configPath = getConfigPath(paseoHome);
const result = PersistedConfigSchema.safeParse(config); const result = PersistedConfigSchema.safeParse(config);
@@ -71,7 +91,7 @@ export function savePersistedConfig(
try { try {
writeFileSync(configPath, JSON.stringify(result.data, null, 2) + "\n"); writeFileSync(configPath, JSON.stringify(result.data, null, 2) + "\n");
console.log(`[Config] Saved to ${configPath}`); logger?.info(`Saved to ${configPath}`);
} catch (err) { } catch (err) {
const message = err instanceof Error ? err.message : String(err); const message = err instanceof Error ? err.message : String(err);
throw new Error(`[Config] Failed to write ${configPath}: ${message}`); throw new Error(`[Config] Failed to write ${configPath}: ${message}`);
@@ -7,6 +7,9 @@ import type {
AgentRegistry, AgentRegistry,
StoredAgentRecord, StoredAgentRecord,
} from "./agent/agent-registry.js"; } from "./agent/agent-registry.js";
import { getRootLogger } from "./logger.js";
const logger = getRootLogger().child({ module: "persistence" });
type AgentRegistryPersistence = Pick<AgentRegistry, "applySnapshot" | "list">; type AgentRegistryPersistence = Pick<AgentRegistry, "applySnapshot" | "list">;
type AgentManagerStateSource = Pick<AgentManager, "subscribe">; type AgentManagerStateSource = Pick<AgentManager, "subscribe">;
@@ -28,7 +31,7 @@ export function attachAgentRegistryPersistence(
return; return;
} }
void registry.applySnapshot(event.agent).catch((error) => { void registry.applySnapshot(event.agent).catch((error) => {
console.error("[AgentRegistry] Failed to persist agent snapshot:", error); logger.error({ err: error, agentId: event.agent.id }, "Failed to persist agent snapshot");
}); });
}); });
+22 -17
View File
@@ -2,6 +2,9 @@ import { readFile, writeFile, readdir, unlink, mkdir, stat } from "fs/promises";
import { join } from "path"; import { join } from "path";
import type { ModelMessage } from "@ai-sdk/provider-utils"; import type { ModelMessage } from "@ai-sdk/provider-utils";
import { standardizePrompt } from "ai/internal"; import { standardizePrompt } from "ai/internal";
import { getRootLogger } from "./logger.js";
const logger = getRootLogger().child({ module: "persistence" });
const CONVERSATIONS_DIR = join(process.cwd(), "conversations"); const CONVERSATIONS_DIR = join(process.cwd(), "conversations");
@@ -44,13 +47,14 @@ export async function saveConversation(
}; };
await writeFile(filepath, JSON.stringify(data, null, 2), "utf-8"); await writeFile(filepath, JSON.stringify(data, null, 2), "utf-8");
console.log( logger.info(
`[Persistence] Saved conversation ${conversationId} (${messages.length} messages)` { conversationId, messageCount: messages.length },
"Saved conversation"
); );
} catch (error) { } catch (error) {
console.error( logger.error(
`[Persistence] Failed to save conversation ${conversationId}:`, { err: error, conversationId },
error "Failed to save conversation"
); );
throw error; throw error;
} }
@@ -70,7 +74,7 @@ export async function loadConversation(
try { try {
await stat(filepath); await stat(filepath);
} catch { } catch {
console.log(`[Persistence] Conversation ${conversationId} not found`); logger.debug({ conversationId }, "Conversation not found");
return null; return null;
} }
@@ -83,15 +87,16 @@ export async function loadConversation(
prompt: data.messages, prompt: data.messages,
}); });
console.log( logger.info(
`[Persistence] Loaded conversation ${conversationId} (${data.messageCount} messages)` { conversationId, messageCount: data.messageCount },
"Loaded conversation"
); );
return result.messages as ModelMessage[]; return result.messages as ModelMessage[];
} catch (error) { } catch (error) {
console.error( logger.error(
`[Persistence] Failed to load conversation ${conversationId}:`, { err: error, conversationId },
error "Failed to load conversation"
); );
return null; return null;
} }
@@ -121,7 +126,7 @@ export async function listConversations(): Promise<ConversationMetadata[]> {
messageCount: data.messageCount, messageCount: data.messageCount,
}); });
} catch (error) { } catch (error) {
console.error(`[Persistence] Failed to read conversation ${file}:`, error); logger.error({ err: error, file }, "Failed to read conversation");
// Skip invalid files // Skip invalid files
} }
} }
@@ -131,7 +136,7 @@ export async function listConversations(): Promise<ConversationMetadata[]> {
return conversations; return conversations;
} catch (error) { } catch (error) {
console.error("[Persistence] Failed to list conversations:", error); logger.error({ err: error }, "Failed to list conversations");
return []; return [];
} }
} }
@@ -143,11 +148,11 @@ export async function deleteConversation(conversationId: string): Promise<void>
try { try {
const filepath = join(CONVERSATIONS_DIR, `${conversationId}.json`); const filepath = join(CONVERSATIONS_DIR, `${conversationId}.json`);
await unlink(filepath); await unlink(filepath);
console.log(`[Persistence] Deleted conversation ${conversationId}`); logger.info({ conversationId }, "Deleted conversation");
} catch (error) { } catch (error) {
console.error( logger.error(
`[Persistence] Failed to delete conversation ${conversationId}:`, { err: error, conversationId },
error "Failed to delete conversation"
); );
throw error; throw error;
} }
@@ -1,5 +1,8 @@
import { getRootLogger } from "../logger.js";
import type { PushTokenStore } from "./token-store.js"; import type { PushTokenStore } from "./token-store.js";
const logger = getRootLogger().child({ module: "push", component: "push-service" });
interface PushPayload { interface PushPayload {
title: string; title: string;
body: string; body: string;
@@ -71,8 +74,9 @@ export class PushService {
}); });
if (!response.ok) { if (!response.ok) {
console.error( logger.error(
`[PushService] Expo push API error: ${response.status} ${response.statusText}` { status: response.status, statusText: response.statusText },
"Expo push API error"
); );
return; return;
} }
@@ -80,7 +84,7 @@ export class PushService {
const result = (await response.json()) as { data: ExpoPushTicket[] }; const result = (await response.json()) as { data: ExpoPushTicket[] };
this.handleTickets(messages, result.data); this.handleTickets(messages, result.data);
} catch (error) { } catch (error) {
console.error("[PushService] Failed to send push notifications:", error); logger.error({ err: error }, "Failed to send push notifications");
} }
} }
@@ -93,9 +97,9 @@ export class PushService {
const message = messages[i]; const message = messages[i];
if (ticket.status === "error") { if (ticket.status === "error") {
console.error( logger.error(
`[PushService] Push failed for token: ${ticket.message}`, { token: message.to, message: ticket.message, details: ticket.details },
ticket.details "Push failed for token"
); );
// Remove invalid tokens // Remove invalid tokens
@@ -1,3 +1,7 @@
import { getRootLogger } from "../logger.js";
const logger = getRootLogger().child({ module: "push", component: "token-store" });
/** /**
* Simple in-memory store for Expo push tokens. * Simple in-memory store for Expo push tokens.
* Tokens are used to send push notifications when all clients are stale. * Tokens are used to send push notifications when all clients are stale.
@@ -7,13 +11,13 @@ export class PushTokenStore {
addToken(token: string): void { addToken(token: string): void {
this.tokens.add(token); this.tokens.add(token);
console.log(`[PushTokenStore] Added token (total: ${this.tokens.size})`); logger.debug({ total: this.tokens.size }, "Added token");
} }
removeToken(token: string): void { removeToken(token: string): void {
const deleted = this.tokens.delete(token); const deleted = this.tokens.delete(token);
if (deleted) { if (deleted) {
console.log(`[PushTokenStore] Removed token (total: ${this.tokens.size})`); logger.debug({ total: this.tokens.size }, "Removed token");
} }
} }
File diff suppressed because it is too large Load Diff
+38 -44
View File
@@ -16,6 +16,9 @@ import type { AgentProvider } from "./agent/agent-sdk-types.js";
import { DownloadTokenStore } from "./file-download/token-store.js"; import { DownloadTokenStore } from "./file-download/token-store.js";
import { PushTokenStore } from "./push/token-store.js"; import { PushTokenStore } from "./push/token-store.js";
import { PushService } from "./push/push-service.js"; import { PushService } from "./push/push-service.js";
import { getRootLogger } from "./logger.js";
const logger = getRootLogger().child({ module: "websocket-server" });
type AgentMcpClientConfig = { type AgentMcpClientConfig = {
agentMcpUrl: string; agentMcpUrl: string;
@@ -68,7 +71,7 @@ export class VoiceAssistantWebSocketServer {
if (!origin || allowedOrigins.has(origin)) { if (!origin || allowedOrigins.has(origin)) {
callback(true); callback(true);
} else { } else {
console.warn(`[WebSocket] Rejected connection from origin: ${origin}`); logger.warn({ origin }, "Rejected connection from origin");
callback(false, 403, "Origin not allowed"); callback(false, 403, "Origin not allowed");
} }
}, },
@@ -82,7 +85,7 @@ export class VoiceAssistantWebSocketServer {
this.broadcastAgentAttention(params); this.broadcastAgentAttention(params);
}); });
console.log("✓ WebSocket server initialized on /ws"); logger.info("WebSocket server initialized on /ws");
} }
/** /**
@@ -99,19 +102,16 @@ export class VoiceAssistantWebSocketServer {
// Load conversation if ID provided // Load conversation if ID provided
let initialMessages = null; let initialMessages = null;
if (conversationId) { if (conversationId) {
console.log( logger.debug({ conversationId }, "Client requesting conversation");
`[WS] Client requesting conversation ${conversationId}`
);
initialMessages = await loadConversation(conversationId); initialMessages = await loadConversation(conversationId);
if (initialMessages) { if (initialMessages) {
console.log( logger.debug(
`[WS] Loaded conversation ${conversationId} with ${initialMessages.length} messages` { conversationId, messageCount: initialMessages.length },
"Loaded conversation"
); );
} else { } else {
console.log( logger.debug({ conversationId }, "Conversation not found, starting fresh");
`[WS] Conversation ${conversationId} not found, starting fresh`
);
} }
} }
@@ -136,10 +136,9 @@ export class VoiceAssistantWebSocketServer {
this.sessions.set(ws, session); this.sessions.set(ws, session);
this.conversationIdToWs.set(session.getConversationId(), ws); this.conversationIdToWs.set(session.getConversationId(), ws);
console.log( logger.info(
`[WS] Client connected: ${clientId} with conversation ${session.getConversationId()} (total: ${ { clientId, conversationId: session.getConversationId(), totalSessions: this.sessions.size },
this.sessions.size "Client connected"
})`
); );
// Don't send initial state here - client will request it via load_conversation_request // Don't send initial state here - client will request it via load_conversation_request
@@ -155,10 +154,9 @@ export class VoiceAssistantWebSocketServer {
const session = this.sessions.get(ws); const session = this.sessions.get(ws);
if (!session) return; if (!session) return;
console.log( logger.info(
`[WS] Client disconnected: ${clientId} (total: ${ { clientId, totalSessions: this.sessions.size - 1 },
this.sessions.size - 1 "Client disconnected"
})`
); );
// Clean up session // Clean up session
@@ -168,15 +166,13 @@ export class VoiceAssistantWebSocketServer {
this.sessions.delete(ws); this.sessions.delete(ws);
this.conversationIdToWs.delete(session.getConversationId()); this.conversationIdToWs.delete(session.getConversationId());
console.log(`[WS] Conversation ${session.getConversationId()} deleted`); logger.debug({ conversationId: session.getConversationId() }, "Conversation deleted");
}); });
// Set up error handler // Set up error handler
ws.on("error", async (error) => { ws.on("error", async (error) => {
// Safe error logging const err = error instanceof Error ? error : new Error(String(error));
const errorMessage = error instanceof Error ? error.message : "Unknown error"; logger.error({ err }, "Client error");
const errorStack = error instanceof Error ? error.stack : undefined;
console.error(`[WS] Client error:`, { message: errorMessage, stack: errorStack });
const session = this.sessions.get(ws); const session = this.sessions.get(ws);
if (!session) return; if (!session) return;
@@ -210,7 +206,7 @@ export class VoiceAssistantWebSocketServer {
sessionMessageType: message.message.type, sessionMessageType: message.message.type,
} : {}), } : {}),
}; };
console.log(`[WS] Received message:`, messageSummary); logger.debug(messageSummary, "Received message");
// Handle WebSocket-level messages // Handle WebSocket-level messages
switch (message.type) { switch (message.type) {
@@ -219,7 +215,7 @@ export class VoiceAssistantWebSocketServer {
return; return;
case "recording_state": case "recording_state":
console.log(`[WS] Recording state: ${message.isRecording}`); logger.debug({ isRecording: message.isRecording }, "Recording state");
return; return;
case "session": case "session":
@@ -228,27 +224,25 @@ export class VoiceAssistantWebSocketServer {
if (sessionMessage) { if (sessionMessage) {
// Debug: Log create_agent_request details // Debug: Log create_agent_request details
if (sessionMessage.type === "create_agent_request") { if (sessionMessage.type === "create_agent_request") {
console.log("[WS] create_agent_request details:", { logger.debug({
cwd: sessionMessage.config.cwd, cwd: sessionMessage.config.cwd,
initialMode: sessionMessage.config.modeId, initialMode: sessionMessage.config.modeId,
worktreeName: sessionMessage.worktreeName, worktreeName: sessionMessage.worktreeName,
requestId: sessionMessage.requestId, requestId: sessionMessage.requestId,
}); }, "create_agent_request details");
} }
const session = this.sessions.get(ws); const session = this.sessions.get(ws);
if (session) { if (session) {
await session.handleMessage(sessionMessage); await session.handleMessage(sessionMessage);
} else { } else {
console.error("[WS] No session found for client"); logger.error("No session found for client");
} }
} }
return; return;
} }
} catch (error) { } catch (error) {
// Safe error logging - avoid crashing on large/circular objects const err = error instanceof Error ? error : new Error(String(error));
const errorMessage = error instanceof Error ? error.message : "Unknown error";
const errorStack = error instanceof Error ? error.stack : undefined;
let rawPayload: string | null = null; let rawPayload: string | null = null;
let parsedPayload: unknown = null; let parsedPayload: unknown = null;
@@ -269,7 +263,8 @@ export class VoiceAssistantWebSocketServer {
} catch (payloadError) { } catch (payloadError) {
rawPayload = rawPayload ?? "<unreadable>"; rawPayload = rawPayload ?? "<unreadable>";
parsedPayload = parsedPayload ?? rawPayload; parsedPayload = parsedPayload ?? rawPayload;
console.error("[WS] Failed to decode raw payload:", payloadError); const payloadErr = payloadError instanceof Error ? payloadError : new Error(String(payloadError));
logger.error({ err: payloadErr }, "Failed to decode raw payload");
} }
const trimmedRawPayload = const trimmedRawPayload =
@@ -277,12 +272,11 @@ export class VoiceAssistantWebSocketServer {
? `${rawPayload.slice(0, 2000)}... (truncated)` ? `${rawPayload.slice(0, 2000)}... (truncated)`
: rawPayload; : rawPayload;
console.error("[WS] Failed to parse/handle message:", { logger.error({
message: errorMessage, err,
stack: errorStack,
rawPayload: trimmedRawPayload, rawPayload: trimmedRawPayload,
parsedPayload, parsedPayload,
}); }, "Failed to parse/handle message");
// Send error to client // Send error to client
this.sendToClient( this.sendToClient(
ws, ws,
@@ -290,7 +284,7 @@ export class VoiceAssistantWebSocketServer {
type: "status", type: "status",
payload: { payload: {
status: "error", status: "error",
message: `Invalid message: ${errorMessage}`, message: `Invalid message: ${err.message}`,
}, },
}) })
); );
@@ -356,20 +350,20 @@ export class VoiceAssistantWebSocketServer {
} { } {
const activity = session.getClientActivity(); const activity = session.getClientActivity();
if (!activity) { if (!activity) {
console.log("[WS] getClientActivityState: no activity for session"); logger.debug("getClientActivityState: no activity for session");
return { deviceType: null, focusedAgentId: null, isStale: true, appVisible: false }; return { deviceType: null, focusedAgentId: null, isStale: true, appVisible: false };
} }
const now = Date.now(); const now = Date.now();
const ageMs = now - activity.lastActivityAt.getTime(); const ageMs = now - activity.lastActivityAt.getTime();
const isStale = ageMs >= this.ACTIVITY_THRESHOLD_MS; const isStale = ageMs >= this.ACTIVITY_THRESHOLD_MS;
console.log("[WS] getClientActivityState", { logger.debug({
deviceType: activity.deviceType, deviceType: activity.deviceType,
focusedAgentId: activity.focusedAgentId, focusedAgentId: activity.focusedAgentId,
lastActivityAt: activity.lastActivityAt.toISOString(), lastActivityAt: activity.lastActivityAt.toISOString(),
ageMs, ageMs,
isStale, isStale,
appVisible: activity.appVisible, appVisible: activity.appVisible,
}); }, "getClientActivityState");
return { return {
deviceType: activity.deviceType, deviceType: activity.deviceType,
focusedAgentId: activity.focusedAgentId, focusedAgentId: activity.focusedAgentId,
@@ -481,19 +475,19 @@ export class VoiceAssistantWebSocketServer {
const allStates = clientEntries.map((e) => e.state); const allStates = clientEntries.map((e) => e.state);
console.log("[WS] broadcastAgentAttention", { logger.debug({
agentId: params.agentId, agentId: params.agentId,
reason: params.reason, reason: params.reason,
clientCount: clientEntries.length, clientCount: clientEntries.length,
allStates, allStates,
}); }, "broadcastAgentAttention");
// Check if all clients are stale - if so, send push notification // Check if all clients are stale - if so, send push notification
const allClientsStale = allStates.every((state) => state.isStale); const allClientsStale = allStates.every((state) => state.isStale);
console.log("[WS] allClientsStale:", allClientsStale); logger.debug({ allClientsStale }, "Client staleness check");
if (allClientsStale) { if (allClientsStale) {
const tokens = this.pushTokenStore.getAllTokens(); const tokens = this.pushTokenStore.getAllTokens();
console.log("[WS] Sending push notification, tokens:", tokens.length); logger.info({ tokenCount: tokens.length }, "Sending push notification");
if (tokens.length > 0) { if (tokens.length > 0) {
void this.pushService.sendPush(tokens, { void this.pushService.sendPush(tokens, {
title: "Agent needs attention", title: "Agent needs attention",
@@ -3,12 +3,15 @@ import { createOpenAI } from "@ai-sdk/openai";
import { z } from "zod"; import { z } from "zod";
import type { AgentTimelineItem } from "../server/agent/agent-sdk-types.js"; import type { AgentTimelineItem } from "../server/agent/agent-sdk-types.js";
import { curateAgentActivity } from "../server/agent/activity-curator.js"; import { curateAgentActivity } from "../server/agent/activity-curator.js";
import { getRootLogger } from "../server/logger.js";
const logger = getRootLogger().child({ module: "agent-title-generator" });
let openai: ReturnType<typeof createOpenAI> | null = null; let openai: ReturnType<typeof createOpenAI> | null = null;
export function initializeTitleGenerator(apiKey: string): void { export function initializeTitleGenerator(apiKey: string): void {
openai = createOpenAI({ apiKey }); openai = createOpenAI({ apiKey });
console.log("✓ Agent title generator initialized"); logger.info("Agent title generator initialized");
} }
export function isTitleGeneratorInitialized(): boolean { export function isTitleGeneratorInitialized(): boolean {
@@ -56,11 +59,11 @@ ${activityContext}`,
temperature: 0.7, temperature: 0.7,
}); });
console.log(`[TitleGenerator] Generated title: "${object.title}"`); logger.debug({ title: object.title }, "Generated agent title");
return object.title; return object.title;
} catch (error: any) { } catch (err) {
console.error("[TitleGenerator] Failed to generate title:", error); logger.error({ err }, "Failed to generate agent title");
return "New Agent"; return "New Agent";
} }
} }
+58 -58
View File
@@ -106,7 +106,7 @@ program
acceptanceCriteria: opts.accept, acceptanceCriteria: opts.accept,
}); });
console.log(task.id); process.stdout.write(`${task.id}\n`);
}); });
program program
@@ -129,7 +129,7 @@ program
const deps = t.deps.length ? ` <- [${t.deps.join(", ")}]` : ""; const deps = t.deps.length ? ` <- [${t.deps.join(", ")}]` : "";
const assignee = t.assignee ? ` @${t.assignee}` : ""; const assignee = t.assignee ? ` @${t.assignee}` : "";
const parent = t.parentId ? ` ^${t.parentId}` : ""; const parent = t.parentId ? ` ^${t.parentId}` : "";
console.log(`${t.id} [${t.status}] ${t.title}${assignee}${parent}${deps}`); process.stdout.write(`${t.id} [${t.status}] ${t.title}${assignee}${parent}${deps}\n`);
} }
}); });
@@ -139,7 +139,7 @@ program
.action(async (id) => { .action(async (id) => {
const task = await store.get(id); const task = await store.get(id);
if (!task) { if (!task) {
console.error(`Task not found: ${id}`); process.stderr.write(`Task not found: ${id}\n`);
process.exit(1); process.exit(1);
} }
@@ -148,44 +148,44 @@ program
// Print ancestors first (root to immediate parent) // Print ancestors first (root to immediate parent)
if (ancestors.length > 0) { if (ancestors.length > 0) {
console.log("# Parent Context\n"); process.stdout.write("# Parent Context\n\n");
for (const ancestor of ancestors.reverse()) { for (const ancestor of ancestors.reverse()) {
console.log(`## ${ancestor.title} (${ancestor.id}) [${ancestor.status}]`); process.stdout.write(`## ${ancestor.title} (${ancestor.id}) [${ancestor.status}]\n`);
if (ancestor.body) { if (ancestor.body) {
console.log(`\n${ancestor.body}`); process.stdout.write(`\n${ancestor.body}\n`);
} }
console.log(""); process.stdout.write("\n");
} }
console.log("---\n"); process.stdout.write("---\n\n");
} }
// Print current task // Print current task
console.log(`# ${task.title}\n`); process.stdout.write(`# ${task.title}\n\n`);
console.log(`id: ${task.id}`); process.stdout.write(`id: ${task.id}\n`);
console.log(`status: ${task.status}`); process.stdout.write(`status: ${task.status}\n`);
console.log(`created: ${task.created}`); process.stdout.write(`created: ${task.created}\n`);
if (task.assignee) { if (task.assignee) {
console.log(`assignee: ${task.assignee}`); process.stdout.write(`assignee: ${task.assignee}\n`);
} }
if (task.parentId) { if (task.parentId) {
console.log(`parent: ${task.parentId}`); process.stdout.write(`parent: ${task.parentId}\n`);
} }
if (task.deps.length) { if (task.deps.length) {
console.log(`deps: [${task.deps.join(", ")}]`); process.stdout.write(`deps: [${task.deps.join(", ")}]\n`);
} }
if (task.body) { if (task.body) {
console.log(`\n${task.body}`); process.stdout.write(`\n${task.body}\n`);
} }
if (task.acceptanceCriteria.length) { if (task.acceptanceCriteria.length) {
console.log("\n## Acceptance Criteria\n"); process.stdout.write("\n## Acceptance Criteria\n\n");
for (const criterion of task.acceptanceCriteria) { for (const criterion of task.acceptanceCriteria) {
console.log(`- [ ] ${criterion}`); process.stdout.write(`- [ ] ${criterion}\n`);
} }
} }
if (task.notes.length) { if (task.notes.length) {
console.log("\n## Notes"); process.stdout.write("\n## Notes\n");
for (const note of task.notes) { for (const note of task.notes) {
console.log(`\n**${note.timestamp}**\n${note.content}`); process.stdout.write(`\n**${note.timestamp}**\n${note.content}\n`);
} }
} }
}); });
@@ -198,7 +198,7 @@ program
const tasks = await store.getReady(opts.scope); const tasks = await store.getReady(opts.scope);
for (const t of tasks) { for (const t of tasks) {
const assignee = t.assignee ? ` @${t.assignee}` : ""; const assignee = t.assignee ? ` @${t.assignee}` : "";
console.log(`${t.id} ${t.title}${assignee}`); process.stdout.write(`${t.id} ${t.title}${assignee}\n`);
} }
}); });
@@ -209,7 +209,7 @@ program
.action(async (opts) => { .action(async (opts) => {
const tasks = await store.getBlocked(opts.scope); const tasks = await store.getBlocked(opts.scope);
for (const t of tasks) { for (const t of tasks) {
console.log(`${t.id} ${t.title} <- [${t.deps.join(", ")}]`); process.stdout.write(`${t.id} ${t.title} <- [${t.deps.join(", ")}]\n`);
} }
}); });
@@ -220,7 +220,7 @@ program
.action(async (opts) => { .action(async (opts) => {
const tasks = await store.getClosed(opts.scope); const tasks = await store.getClosed(opts.scope);
for (const t of tasks) { for (const t of tasks) {
console.log(`${t.id} ${t.title}`); process.stdout.write(`${t.id} ${t.title}\n`);
} }
}); });
@@ -230,7 +230,7 @@ program
.action(async (id) => { .action(async (id) => {
const root = await store.get(id); const root = await store.get(id);
if (!root) { if (!root) {
console.error(`Task not found: ${id}`); process.stderr.write(`Task not found: ${id}\n`);
process.exit(1); process.exit(1);
} }
@@ -241,8 +241,8 @@ program
// Print a task line with optional dependency info // Print a task line with optional dependency info
const printTask = (task: Task, prefix: string, connector: string) => { const printTask = (task: Task, prefix: string, connector: string) => {
const assignee = task.assignee ? ` @${task.assignee}` : ""; const assignee = task.assignee ? ` @${task.assignee}` : "";
console.log( process.stdout.write(
`${prefix}${connector}${task.id} [${task.status}] ${task.title}${assignee}` `${prefix}${connector}${task.id} [${task.status}] ${task.title}${assignee}\n`
); );
// Print dependencies on next line with arrow // Print dependencies on next line with arrow
if (task.deps.length > 0) { if (task.deps.length > 0) {
@@ -253,13 +253,13 @@ program
}) })
.join(", "); .join(", ");
const depPrefix = prefix + (connector === "└── " ? " " : "│ "); const depPrefix = prefix + (connector === "└── " ? " " : "│ ");
console.log(`${depPrefix}→ depends on: ${depNames}`); process.stdout.write(`${depPrefix}→ depends on: ${depNames}\n`);
} }
}; };
// Print root task // Print root task
const rootAssignee = root.assignee ? ` @${root.assignee}` : ""; const rootAssignee = root.assignee ? ` @${root.assignee}` : "";
console.log(`${root.id} [${root.status}] ${root.title}${rootAssignee}`); process.stdout.write(`${root.id} [${root.status}] ${root.title}${rootAssignee}\n`);
if (root.deps.length > 0) { if (root.deps.length > 0) {
const depNames = root.deps const depNames = root.deps
.map((depId) => { .map((depId) => {
@@ -267,7 +267,7 @@ program
return dep ? `${dep.title} (${depId})` : depId; return dep ? `${dep.title} (${depId})` : depId;
}) })
.join(", "); .join(", ");
console.log(`→ depends on: ${depNames}`); process.stdout.write(`→ depends on: ${depNames}\n`);
} }
// Recursively print children (hierarchy) // Recursively print children (hierarchy)
@@ -292,7 +292,7 @@ program
.description("Add dependency (id depends on dep-id)") .description("Add dependency (id depends on dep-id)")
.action(async (id, depId) => { .action(async (id, depId) => {
await store.addDep(id, depId); await store.addDep(id, depId);
console.log(`Added: ${id} -> ${depId}`); process.stdout.write(`Added: ${id} -> ${depId}\n`);
}); });
program program
@@ -300,7 +300,7 @@ program
.description("Remove dependency") .description("Remove dependency")
.action(async (id, depId) => { .action(async (id, depId) => {
await store.removeDep(id, depId); await store.removeDep(id, depId);
console.log(`Removed: ${id} -> ${depId}`); process.stdout.write(`Removed: ${id} -> ${depId}\n`);
}); });
program program
@@ -313,7 +313,7 @@ program
.action(async (id, opts) => { .action(async (id, opts) => {
const task = await store.get(id); const task = await store.get(id);
if (!task) { if (!task) {
console.error(`Task not found: ${id}`); process.stderr.write(`Task not found: ${id}\n`);
process.exit(1); process.exit(1);
} }
@@ -337,14 +337,14 @@ program
} }
if (Object.keys(changes).length === 0 && opts.accept.length === 0) { if (Object.keys(changes).length === 0 && opts.accept.length === 0) {
console.error("No changes specified"); process.stderr.write("No changes specified\n");
process.exit(1); process.exit(1);
} }
if (Object.keys(changes).length > 0) { if (Object.keys(changes).length > 0) {
await store.update(id, changes); await store.update(id, changes);
} }
console.log(`Updated: ${id}`); process.stdout.write(`Updated: ${id}\n`);
}); });
program program
@@ -354,20 +354,20 @@ program
.option("--root", "Make this a root task (remove parent)") .option("--root", "Make this a root task (remove parent)")
.action(async (id, opts) => { .action(async (id, opts) => {
if (!opts.parent && !opts.root) { if (!opts.parent && !opts.root) {
console.error("Must specify --parent <id> or --root"); process.stderr.write("Must specify --parent <id> or --root\n");
process.exit(1); process.exit(1);
} }
if (opts.parent && opts.root) { if (opts.parent && opts.root) {
console.error("Cannot specify both --parent and --root"); process.stderr.write("Cannot specify both --parent and --root\n");
process.exit(1); process.exit(1);
} }
await store.setParent(id, opts.root ? null : opts.parent); await store.setParent(id, opts.root ? null : opts.parent);
if (opts.root) { if (opts.root) {
console.log(`${id} is now a root task`); process.stdout.write(`${id} is now a root task\n`);
} else { } else {
console.log(`${id} moved to parent ${opts.parent}`); process.stdout.write(`${id} moved to parent ${opts.parent}\n`);
} }
}); });
@@ -377,19 +377,19 @@ program
.action(async (id) => { .action(async (id) => {
const task = await store.get(id); const task = await store.get(id);
if (!task) { if (!task) {
console.error(`Task not found: ${id}`); process.stderr.write(`Task not found: ${id}\n`);
process.exit(1); process.exit(1);
} }
const children = await store.getChildren(id); const children = await store.getChildren(id);
if (children.length === 0) { if (children.length === 0) {
console.log("No children"); process.stdout.write("No children\n");
return; return;
} }
for (const child of children) { for (const child of children) {
const assignee = child.assignee ? ` @${child.assignee}` : ""; const assignee = child.assignee ? ` @${child.assignee}` : "";
console.log(`${child.id} [${child.status}] ${child.title}${assignee}`); process.stdout.write(`${child.id} [${child.status}] ${child.title}${assignee}\n`);
} }
}); });
@@ -398,7 +398,7 @@ program
.description("Add a timestamped note") .description("Add a timestamped note")
.action(async (id, content) => { .action(async (id, content) => {
await store.addNote(id, content); await store.addNote(id, content);
console.log("Note added"); process.stdout.write("Note added\n");
}); });
program program
@@ -406,7 +406,7 @@ program
.description("Mark draft as open (actionable)") .description("Mark draft as open (actionable)")
.action(async (id) => { .action(async (id) => {
await store.open(id); await store.open(id);
console.log(`${id} -> open`); process.stdout.write(`${id} -> open\n`);
}); });
program program
@@ -414,7 +414,7 @@ program
.description("Mark as in progress") .description("Mark as in progress")
.action(async (id) => { .action(async (id) => {
await store.start(id); await store.start(id);
console.log(`${id} -> in_progress`); process.stdout.write(`${id} -> in_progress\n`);
}); });
program program
@@ -423,7 +423,7 @@ program
.description("Mark as done") .description("Mark as done")
.action(async (id) => { .action(async (id) => {
await store.close(id); await store.close(id);
console.log(`${id} -> done`); process.stdout.write(`${id} -> done\n`);
}); });
program program
@@ -431,7 +431,7 @@ program
.description("Mark as failed (catastrophically stuck)") .description("Mark as failed (catastrophically stuck)")
.action(async (id) => { .action(async (id) => {
await store.fail(id); await store.fail(id);
console.log(`${id} -> failed`); process.stdout.write(`${id} -> failed\n`);
}); });
// Agent runner // Agent runner
@@ -741,7 +741,7 @@ function getLogFile(): string {
function log(logFile: string, message: string): void { function log(logFile: string, message: string): void {
const timestamp = new Date().toISOString(); const timestamp = new Date().toISOString();
appendFileSync(logFile, `[${timestamp}] ${message}\n`); appendFileSync(logFile, `[${timestamp}] ${message}\n`);
console.log(`[${timestamp}] ${message}`); process.stdout.write(`[${timestamp}] ${message}\n`);
} }
function parseJudgeVerdict(output: string): "DONE" | "NOT_DONE" | null { function parseJudgeVerdict(output: string): "DONE" | "NOT_DONE" | null {
@@ -767,13 +767,13 @@ program
const watchMode = opts.watch; const watchMode = opts.watch;
const logFile = getLogFile(); const logFile = getLogFile();
console.log("Task Runner started (planner/worker/judge loop)"); process.stdout.write("Task Runner started (planner/worker/judge loop)\n");
console.log(`Planner: ${enablePlanner ? `${plannerModel} (replan every ${replanInterval} tasks)` : "disabled"}`); process.stdout.write(`Planner: ${enablePlanner ? `${plannerModel} (replan every ${replanInterval} tasks)` : "disabled"}\n`);
console.log(`Judge: ${judgeModel}`); process.stdout.write(`Judge: ${judgeModel}\n`);
console.log(`Max iterations: ${maxIterations === 0 ? "unlimited" : maxIterations}`); process.stdout.write(`Max iterations: ${maxIterations === 0 ? "unlimited" : maxIterations}\n`);
if (scopeId) console.log(`Scope: ${scopeId}`); if (scopeId) process.stdout.write(`Scope: ${scopeId}\n`);
console.log(`Log: ${logFile}`); process.stdout.write(`Log: ${logFile}\n`);
console.log(""); process.stdout.write("\n");
log(logFile, `Started with planner=${enablePlanner ? plannerModel : "disabled"} replan=${replanInterval} judge=${judgeModel} maxIter=${maxIterations} scope=${scopeId || "all"}`); log(logFile, `Started with planner=${enablePlanner ? plannerModel : "disabled"} replan=${replanInterval} judge=${judgeModel} maxIter=${maxIterations} scope=${scopeId || "all"}`);
@@ -928,19 +928,19 @@ program
await runTaskLoop(); await runTaskLoop();
if (watchMode) { if (watchMode) {
console.log("💤 Waiting for new tasks..."); process.stdout.write("💤 Waiting for new tasks...\n");
while (true) { while (true) {
await new Promise((r) => setTimeout(r, 5000)); await new Promise((r) => setTimeout(r, 5000));
const ready = await store.getReady(scopeId); const ready = await store.getReady(scopeId);
if (ready.length > 0) { if (ready.length > 0) {
await runTaskLoop(); await runTaskLoop();
console.log("💤 Waiting for new tasks..."); process.stdout.write("💤 Waiting for new tasks...\n");
} }
} }
} }
console.log(""); process.stdout.write("\n");
console.log(`All tasks complete. (${new Date().toISOString()})`); process.stdout.write(`All tasks complete. (${new Date().toISOString()})\n`);
log(logFile, "All tasks complete"); log(logFile, "All tasks complete");
}); });