feat(bot): add error handling and logging for bot subprocesses, including last error tracking and log retrieval functionality

This commit is contained in:
Ivan
2026-05-02 04:34:45 -05:00
parent 61b7de27dd
commit 5784b70ee2
4 changed files with 343 additions and 39 deletions
+88 -2
View File
@@ -125,6 +125,62 @@ class BotHandler:
return None
return BotHandler._normalize_lxmf_hash_hex(raw)
@staticmethod
def _read_bot_last_error(storage_dir):
if not storage_dir:
return None
path = os.path.join(storage_dir, "meshchatx_bot_last_error.txt")
try:
with open(path, encoding="utf-8") as f:
text = f.read().strip()
except OSError:
return None
if not text:
return None
max_len = 1600
if len(text) > max_len:
return text[:max_len] + "\n..."
return text
@staticmethod
def _subprocess_log_path(storage_dir):
if not storage_dir:
return None
return os.path.join(storage_dir, "meshchatx_bot_subprocess.log")
def read_subprocess_log(self, bot_id, max_bytes=524_288):
entry = None
for e in self.bots_state:
if e.get("id") == bot_id:
entry = e
break
if entry is None:
raise ValueError(f"Unknown bot: {bot_id}")
storage_dir = entry.get("storage_dir")
path = BotHandler._subprocess_log_path(storage_dir)
if not path:
return {"log": None, "truncated": False, "total_bytes": 0}
try:
total = os.path.getsize(path)
except OSError:
return {"log": None, "truncated": False, "total_bytes": 0}
if total == 0:
return {"log": "", "truncated": False, "total_bytes": 0}
truncated = total > max_bytes
to_read = min(total, max_bytes)
try:
with open(path, "rb") as f:
if truncated:
f.seek(total - to_read)
raw = f.read()
except OSError:
return {"log": None, "truncated": False, "total_bytes": total}
text = raw.decode("utf-8", errors="replace")
if truncated and "\n" in text:
_first, _sep, rest = text.partition("\n")
text = rest if rest else _first
return {"log": text, "truncated": truncated, "total_bytes": total}
def get_status(self):
bots: list[dict] = []
@@ -180,6 +236,9 @@ class BotHandler:
with contextlib.suppress(Exception):
address_pretty = RNS.prettyhexrep(bytes.fromhex(address_full))
storage_dir = entry.get("storage_dir")
last_err = self._read_bot_last_error(storage_dir)
bots.append(
{
"id": bot_id,
@@ -191,7 +250,8 @@ class BotHandler:
"full_address": address_full,
"running": running,
"pid": pid,
"storage_dir": entry.get("storage_dir"),
"storage_dir": storage_dir,
"last_error": last_err,
},
)
@@ -237,6 +297,10 @@ class BotHandler:
os.makedirs(bot_storage_dir, exist_ok=True)
err_file = os.path.join(bot_storage_dir, "meshchatx_bot_last_error.txt")
with contextlib.suppress(OSError):
os.unlink(err_file)
cmd = [
sys.executable,
self.runner_path,
@@ -252,7 +316,29 @@ class BotHandler:
entry["reticulum_config_dir"],
]
proc = subprocess.Popen(cmd, cwd=bot_storage_dir)
subprocess_log = os.path.join(bot_storage_dir, "meshchatx_bot_subprocess.log")
log_f = open(
subprocess_log,
"a",
encoding="utf-8",
)
try:
log_f.write(f"\n--- start {time.strftime('%Y-%m-%d %H:%M:%S')} ---\n")
log_f.flush()
proc = subprocess.Popen(
cmd,
cwd=bot_storage_dir,
stdout=log_f,
stderr=subprocess.STDOUT,
start_new_session=True,
env={**os.environ, "PYTHONUNBUFFERED": "1"},
)
except Exception:
log_f.close()
raise
else:
log_f.close()
entry["pid"] = proc.pid
self._save_state()
+31 -11
View File
@@ -5,6 +5,7 @@ import contextlib
import os
import threading
import time
import traceback
from meshchatx.src.backend.bot_templates import (
EchoBotTemplate,
@@ -52,6 +53,11 @@ def main():
)
args = parser.parse_args()
storage_abs = os.path.abspath(args.storage)
err_path = os.path.join(storage_abs, "meshchatx_bot_last_error.txt")
with contextlib.suppress(OSError):
os.unlink(err_path)
os.makedirs(args.storage, exist_ok=True)
config_path = args.config_path
@@ -65,16 +71,22 @@ def main():
)
os.makedirs(reticulum_config_dir, exist_ok=True)
BotCls = TEMPLATE_MAP[args.template]
bot_instance = BotCls(
name=args.name,
storage_path=args.storage,
test_mode=False,
config_path=config_path,
reticulum_config_dir=reticulum_config_dir,
)
storage_abs = os.path.abspath(args.storage)
try:
BotCls = TEMPLATE_MAP[args.template]
bot_instance = BotCls(
name=args.name,
storage_path=args.storage,
test_mode=False,
config_path=config_path,
reticulum_config_dir=reticulum_config_dir,
)
except BaseException:
try:
with open(err_path, "w", encoding="utf-8") as ef:
traceback.print_exc(file=ef)
except OSError:
pass
raise
with contextlib.suppress(OSError):
with open(
os.path.join(config_path, "bot_display_name.txt"),
@@ -112,7 +124,15 @@ def main():
elif hasattr(bot_instance.bot, "_announce"):
bot_instance.bot._announce()
bot_instance.run()
try:
bot_instance.run()
except BaseException:
try:
with open(err_path, "w", encoding="utf-8") as ef:
traceback.print_exc(file=ef)
except OSError:
pass
raise
if __name__ == "__main__":
@@ -132,6 +132,14 @@
>
<MaterialDesignIcon icon-name="play" class="size-5" />
</button>
<button
type="button"
class="p-2 rounded-lg text-gray-500 dark:text-gray-400 hover:text-violet-600 dark:hover:text-violet-400 hover:bg-gray-100/80 dark:hover:bg-zinc-800/80 transition-colors"
:title="$t('bots.view_process_log')"
@click="openProcessLog(bot)"
>
<MaterialDesignIcon icon-name="bug-outline" class="size-5" />
</button>
<button
type="button"
class="p-2 rounded-lg text-gray-500 dark:text-gray-400 hover:text-gray-900 dark:hover:text-white hover:bg-gray-100/80 dark:hover:bg-zinc-800/80 transition-colors"
@@ -217,33 +225,61 @@
bot.running ? $t("bots.status_running") : $t("bots.status_stopped")
}}</span>
</div>
<div class="text-[11px] text-gray-500 dark:text-gray-400">
<span class="font-semibold text-gray-600 dark:text-gray-300">{{
$t("bots.lxmf_address")
}}</span>
<button
v-if="lxmfAddressFor(bot)"
type="button"
class="font-mono break-all text-left text-gray-800 dark:text-gray-200 hover:underline"
@click="copyLxmfAddress(bot)"
<dl class="space-y-2.5 text-[11px] text-gray-600 dark:text-gray-300 min-w-0">
<div class="min-w-0">
<dt
class="text-[10px] font-semibold uppercase tracking-wide text-gray-500 dark:text-gray-400 mb-1"
>
{{ $t("bots.lxmf_address") }}
</dt>
<dd class="m-0 min-w-0">
<button
v-if="lxmfAddressFor(bot)"
type="button"
class="font-mono text-[11px] break-all text-left w-full max-w-full text-gray-800 dark:text-gray-200 hover:underline leading-snug"
@click="copyLxmfAddress(bot)"
>
{{ lxmfAddressFor(bot) }}
</button>
<span v-else class="text-gray-500 dark:text-gray-400">{{
$t("bots.address_pending")
}}</span>
</dd>
</div>
<div class="min-w-0">
<dt
class="text-[10px] font-semibold uppercase tracking-wide text-gray-500 dark:text-gray-400 mb-1"
>
{{ $t("bots.last_announce") }}
</dt>
<dd class="m-0 text-gray-700 dark:text-gray-200 leading-snug">
<span v-if="bot.last_announce_at">{{
formatRelativeSince(bot.last_announce_at)
}}</span>
<span v-else-if="lxmfAddressFor(bot)">{{
$t("bots.never_announced")
}}</span>
<span v-else></span>
</dd>
</div>
</dl>
<div
v-if="botLastError(bot)"
class="rounded-lg border border-red-200/90 dark:border-red-900/70 bg-red-50/90 dark:bg-red-950/50 px-2.5 py-2 text-[11px] text-red-900 dark:text-red-100"
>
<div class="font-semibold flex items-center gap-1.5">
<MaterialDesignIcon
icon-name="alert-circle-outline"
class="size-4 shrink-0 opacity-90"
/>
{{ $t("bots.last_error_heading") }}
</div>
<pre
class="mt-1.5 m-0 whitespace-pre-wrap break-words font-mono text-[10px] leading-relaxed text-red-800/95 dark:text-red-100/90"
>{{ botLastError(bot) }}</pre
>
{{ lxmfAddressFor(bot) }}
</button>
<span v-else>{{ $t("bots.address_pending") }}</span>
</div>
<div class="text-[11px] text-gray-500 dark:text-gray-400">
<span class="font-semibold text-gray-600 dark:text-gray-300">{{
$t("bots.last_announce")
}}</span>
<span v-if="bot.last_announce_at" class="ml-1.5">{{
formatRelativeSince(bot.last_announce_at)
}}</span>
<span v-else-if="lxmfAddressFor(bot)" class="ml-1.5">{{
$t("bots.never_announced")
}}</span>
<span v-else class="ml-1.5"></span>
</div>
<div class="text-[10px] text-gray-400">
<div class="text-[10px] text-gray-400 pt-0.5">
{{ bot.template_id || bot.template }}
</div>
</div>
@@ -255,6 +291,67 @@
</div>
</div>
<div
v-if="processLogModalBot"
class="fixed inset-0 z-100 flex items-end sm:items-center justify-center p-0 sm:p-4 bg-black/50"
@click.self="closeProcessLog"
>
<div
class="w-full sm:max-w-3xl flex flex-col max-sm:h-[92dvh] max-sm:max-h-[92dvh] sm:max-h-[90vh] rounded-t-2xl sm:rounded-lg border border-gray-200 dark:border-zinc-800 bg-white dark:bg-zinc-950 shadow-xl touch-pan-y min-h-0"
>
<div
class="flex justify-between items-start gap-2 p-3 sm:p-5 border-b border-gray-200 dark:border-zinc-800 shrink-0"
>
<div class="min-w-0 pr-2">
<h3 class="text-lg sm:text-xl font-bold text-gray-900 dark:text-white">
{{ $t("bots.process_log_title") }}
</h3>
<p class="text-sm text-gray-600 dark:text-gray-400 mt-0.5 truncate">
{{ processLogModalBot.name }}
</p>
<p v-if="processLogTruncated" class="text-xs text-amber-700 dark:text-amber-400 mt-1">
{{ $t("bots.process_log_truncated") }}
</p>
</div>
<div class="flex items-center gap-1 shrink-0">
<button
type="button"
class="p-2 rounded-lg text-gray-500 hover:text-gray-900 dark:hover:text-white hover:bg-gray-100/80 dark:hover:bg-zinc-800/80"
:title="$t('bots.copy_process_log')"
:disabled="!processLogText"
@click="copyProcessLog"
>
<MaterialDesignIcon icon-name="content-copy" class="size-5" />
</button>
<button
type="button"
class="p-2 rounded-lg text-gray-500 hover:text-gray-900 dark:hover:text-white hover:bg-gray-100/80 dark:hover:bg-zinc-800/80"
@click="closeProcessLog"
>
<MaterialDesignIcon icon-name="close" class="size-5" />
</button>
</div>
</div>
<div class="flex-1 min-h-0 flex flex-col p-2 sm:p-5 pt-2 sm:pt-2">
<div
v-if="processLogLoading"
class="flex items-center justify-center py-16 text-gray-500 dark:text-gray-400 text-sm"
>
{{ $t("bots.process_log_loading") }}
</div>
<div
v-else
class="flex-1 min-h-0 max-sm:min-h-[55dvh] sm:min-h-[12rem] overflow-auto rounded-lg border border-gray-200 dark:border-zinc-800 bg-gray-50 dark:bg-zinc-900 touch-pan-x"
>
<pre
class="bots-process-log-text m-0 min-h-full w-max min-w-full p-2 sm:p-3 font-mono text-gray-800 dark:text-gray-200 whitespace-pre select-text"
>{{ processLogDisplayText }}</pre
>
</div>
</div>
</div>
</div>
<div
v-if="selectedTemplate"
class="fixed inset-0 z-100 flex items-end sm:items-center justify-center p-0 sm:p-4 bg-black/50"
@@ -340,8 +437,21 @@ export default {
relativeTimerInterval: null,
editingBotId: null,
editingNameDraft: "",
processLogModalBot: null,
processLogText: "",
processLogTruncated: false,
processLogLoading: false,
};
},
computed: {
processLogDisplayText() {
const t = (this.processLogText || "").trim();
if (t) {
return this.processLogText;
}
return this.processLogLoading ? "" : this.$t("bots.process_log_empty");
},
},
mounted() {
this.getStatus();
this.refreshInterval = setInterval(this.getStatus, 5000);
@@ -365,7 +475,7 @@ export default {
this.templates = response.data.templates;
this.loading = false;
} catch (e) {
console.error(e);
console.error("[BotsPage] getStatus failed", e?.response?.data || e?.message || e);
}
},
selectTemplate(template) {
@@ -481,6 +591,44 @@ export default {
ToastUtils.error(e.response?.data?.message || this.$t("bots.announce_failed"));
}
},
botLastError(bot) {
const t = (bot?.last_error || "").trim();
return t;
},
closeProcessLog() {
this.processLogModalBot = null;
this.processLogText = "";
this.processLogTruncated = false;
this.processLogLoading = false;
},
async openProcessLog(bot) {
this.processLogModalBot = bot;
this.processLogText = "";
this.processLogTruncated = false;
this.processLogLoading = true;
try {
const response = await window.api.get("/api/v1/bots/subprocess-log", {
params: { bot_id: bot.id },
});
this.processLogText =
response.data.log === null || response.data.log === undefined ? "" : String(response.data.log);
this.processLogTruncated = Boolean(response.data.truncated);
} catch (e) {
console.error(e);
ToastUtils.error(e.response?.data?.message || this.$t("bots.process_log_failed"));
this.closeProcessLog();
} finally {
this.processLogLoading = false;
}
},
copyProcessLog() {
const t = (this.processLogText || "").trim();
if (!t) {
return;
}
navigator.clipboard.writeText(this.processLogText);
ToastUtils.success(this.$t("bots.process_log_copied"));
},
lxmfAddressFor(bot) {
const raw = bot.lxmf_address || bot.full_address;
if (!raw || typeof raw !== "string") {
@@ -554,4 +702,16 @@ export default {
.glass-label {
@apply block text-sm font-semibold text-gray-700 dark:text-gray-300 mb-1;
}
.bots-process-log-text {
font-size: 0.6875rem;
line-height: 1.55;
-webkit-text-size-adjust: 100%;
text-size-adjust: 100%;
}
@media (max-width: 639px) {
.bots-process-log-text {
font-size: 0.5625rem;
line-height: 1.28;
}
}
</style>
@@ -198,3 +198,41 @@ def test_request_announce_not_running(temp_identity_dir):
]
with pytest.raises(RuntimeError, match="not running"):
handler.request_announce(sid)
def test_get_status_subprocess_log_not_shown_as_last_error(temp_identity_dir):
handler = BotHandler(temp_identity_dir)
sid = "b1"
storage = os.path.join(handler.bots_dir, sid)
os.makedirs(storage, exist_ok=True)
log_path = os.path.join(storage, "meshchatx_bot_subprocess.log")
with open(log_path, "w", encoding="utf-8") as f:
f.write("[Info] Received SIGTERM, shutting down now!\n")
handler.bots_state = [
{"id": sid, "template_id": "echo", "storage_dir": storage, "pid": None}
]
status = handler.get_status()
assert status["bots"][0]["last_error"] is None
def test_read_subprocess_log(temp_identity_dir):
handler = BotHandler(temp_identity_dir)
sid = "b1"
storage = os.path.join(handler.bots_dir, sid)
os.makedirs(storage, exist_ok=True)
log_path = os.path.join(storage, "meshchatx_bot_subprocess.log")
with open(log_path, "w", encoding="utf-8") as f:
f.write("line1\nline2\n")
handler.bots_state = [
{"id": sid, "template_id": "echo", "storage_dir": storage, "pid": None}
]
out = handler.read_subprocess_log(sid)
assert out["truncated"] is False
assert out["total_bytes"] > 0
assert "line2" in (out["log"] or "")
def test_read_subprocess_log_unknown_bot(temp_identity_dir):
handler = BotHandler(temp_identity_dir)
with pytest.raises(ValueError, match="Unknown bot"):
handler.read_subprocess_log("nope")