fix: prevent false timeout failures and release 1.2.2
This commit is contained in:
1 parent
1dc2b0c686
commit
e1e26772d9
18 files changed
+189
-22
No files matched your search
@@ -6,6 +6,8 @@ OPENAI_BASE_URL=https://api-n-cd.playones.com/v1
|
||||
OPENAI_MODEL=mimo-v2.6-flash
|
||||
# 单次模型 HTTP 请求超时(秒)
|
||||
OPENAI_TIMEOUT_SECONDS=300
|
||||
# 可选的后台步骤截图摘要单次超时,独立于上面的主模型请求超时。
|
||||
ARTEMIS_STEP_SUMMARIZER_TIMEOUT_SECONDS=25
|
||||
# 失败后最多重试 5 次,由 Artemis 统一管理,SDK 不叠加重试。
|
||||
OPENAI_MAX_RETRIES=5
|
||||
OPENAI_RETRY_INTERVAL_SECONDS=10
|
||||
|
||||
@@ -95,21 +95,46 @@ def failure_reason(directory: Path, status: str, recorded: str | None) -> str:
|
||||
state = read_json(directory / "status.json", {})
|
||||
if isinstance(state, dict) and state.get("error"):
|
||||
return redact(state["error"])
|
||||
log_lines: list[str] = []
|
||||
for name in ("stdout.log", "stderr.log"):
|
||||
path = directory / name
|
||||
try:
|
||||
with path.open("rb") as stream:
|
||||
stream.seek(0, 2)
|
||||
stream.seek(max(0, stream.tell() - 131072))
|
||||
lines = stream.read().decode("utf-8", errors="replace").splitlines()
|
||||
log_lines.extend(stream.read().decode("utf-8", errors="replace").splitlines())
|
||||
except OSError:
|
||||
continue
|
||||
for line in reversed(lines):
|
||||
match = re.search(r"Error running automation:\s*(.+)", line)
|
||||
if match:
|
||||
return redact(match.group(1))
|
||||
if re.search(r"(?i)(?:timeout|timed out|超时|deadline exceeded)", line):
|
||||
return redact("模型请求或任务执行超时:" + line.strip())
|
||||
for line in reversed(log_lines):
|
||||
match = re.search(r"Error running automation:\s*(.+)", line)
|
||||
if match:
|
||||
return redact(match.group(1))
|
||||
for line in reversed(log_lines):
|
||||
stripped = line.strip()
|
||||
if stripped.startswith(("⚠", "ℹ", "WARNING", "INFO", "DEBUG")):
|
||||
continue
|
||||
if any(
|
||||
name in line
|
||||
for name in (
|
||||
"VisualStepSummarizer:",
|
||||
"StepMemoryService:",
|
||||
"Could not clean unowned screen wake locks",
|
||||
)
|
||||
):
|
||||
continue
|
||||
exception_line = re.fullmatch(
|
||||
r"(?:[A-Za-z_]\w*\.)*[A-Za-z_]\w*(?:Error|Exception|Timeout):\s*.*",
|
||||
stripped,
|
||||
)
|
||||
if exception_line and not re.search(r"(?i)(?:timeout|timed out|超时)", stripped):
|
||||
return redact(stripped)
|
||||
if re.search(
|
||||
r"(?i)(?:\b(?:TimeoutError|APITimeoutError|ReadTimeout|ConnectTimeout)\s*:|"
|
||||
r"(?:模型请求|任务执行|model request|task execution).{0,100}"
|
||||
r"(?:超时|timed out|deadline exceeded))",
|
||||
stripped,
|
||||
):
|
||||
return redact("模型请求或任务执行超时:" + stripped)
|
||||
return "任务未完成,运行日志中没有可提取的具体异常;请查看执行步骤。"
|
||||
|
||||
|
||||
|
||||
Generated
+2
-2
@@ -1,12 +1,12 @@
|
||||
{
|
||||
"name": "artemis-showcase-ui",
|
||||
"version": "1.2.1",
|
||||
"version": "1.2.2",
|
||||
"lockfileVersion": 3,
|
||||
"requires": true,
|
||||
"packages": {
|
||||
"": {
|
||||
"name": "artemis-showcase-ui",
|
||||
"version": "1.2.1",
|
||||
"version": "1.2.2",
|
||||
"dependencies": {
|
||||
"@angular/cdk": "^22.1.5",
|
||||
"@angular/common": "^22.1.4",
|
||||
|
||||
@@ -1,6 +1,6 @@
|
||||
{
|
||||
"name": "artemis-showcase-ui",
|
||||
"version": "1.2.1",
|
||||
"version": "1.2.2",
|
||||
"scripts": {
|
||||
"ng": "ng",
|
||||
"start": "ng serve --proxy-config proxy.conf.json",
|
||||
|
||||
@@ -167,6 +167,7 @@ class FlashRunner:
|
||||
ctx,
|
||||
model_name=self.step_summarizer_cfg.model,
|
||||
retry_limit=self.memory_runtime_cfg.retry_limit,
|
||||
timeout_seconds=self.step_summarizer_cfg.timeout_seconds,
|
||||
max_concurrency=self.memory_runtime_cfg.max_concurrency,
|
||||
flush_timeout_s=self.memory_runtime_cfg.flush_timeout_s,
|
||||
)
|
||||
|
||||
@@ -151,6 +151,7 @@ class VisualStepSummarizer(StepMemoryService):
|
||||
ctx: ArtemisContext,
|
||||
model_name: str | None = None,
|
||||
retry_limit: int = 3,
|
||||
timeout_seconds: float = 25.0,
|
||||
*,
|
||||
max_concurrency: int = 1,
|
||||
flush_timeout_s: float = 30.0,
|
||||
@@ -161,6 +162,7 @@ class VisualStepSummarizer(StepMemoryService):
|
||||
retry_limit=retry_limit,
|
||||
flush_timeout_s=flush_timeout_s,
|
||||
)
|
||||
self._timeout_seconds = timeout_seconds
|
||||
|
||||
# Initialize lightweight VLM: prioritize explicit model_name
|
||||
target_model = model_name or settings.OPENAI_MODEL
|
||||
@@ -459,7 +461,9 @@ class VisualStepSummarizer(StepMemoryService):
|
||||
HumanMessage(content=content_blocks),
|
||||
]
|
||||
|
||||
response = await asyncio.wait_for(self._llm.ainvoke(messages), timeout=25.0)
|
||||
response = await asyncio.wait_for(
|
||||
self._llm.ainvoke(messages), timeout=self._timeout_seconds
|
||||
)
|
||||
self._meter_lens_call(response)
|
||||
summary_raw = response.content if isinstance(response.content, str) else ""
|
||||
if isinstance(response.content, list):
|
||||
@@ -505,8 +509,14 @@ class VisualStepSummarizer(StepMemoryService):
|
||||
logger.debug(f"DataEngine step summary update skipped: {de_err}")
|
||||
return True
|
||||
|
||||
except TimeoutError:
|
||||
logger.warning(
|
||||
f"VisualStepSummarizer: Step {step_number} summary request timed out "
|
||||
f"(limit {self._timeout_seconds:.1f}s)"
|
||||
)
|
||||
except Exception as e:
|
||||
logger.warning(
|
||||
f"VisualStepSummarizer: Error generating summary for step {step_number}: {e}"
|
||||
f"VisualStepSummarizer: Error generating summary for step {step_number}: "
|
||||
f"{type(e).__name__}: {e}"
|
||||
)
|
||||
return False
|
||||
@@ -370,6 +370,11 @@ class StepSummarizerConfig(BaseModel):
|
||||
default_factory=lambda: settings.OPENAI_MODEL,
|
||||
description="Lightweight model used for background step state summarization.",
|
||||
)
|
||||
timeout_seconds: float = Field(
|
||||
default=25.0,
|
||||
gt=0,
|
||||
description="Timeout for one optional background visual-summary model request.",
|
||||
)
|
||||
prune_history_xml: bool = Field(
|
||||
default=True,
|
||||
description="Whether to prune outdated heavy UI XML trees from historical turns.",
|
||||
|
||||
@@ -33,6 +33,7 @@
|
||||
"step_summarizer": {
|
||||
"enabled": "${env:ARTEMIS_STEP_SUMMARIZER_ENABLED:-true}",
|
||||
"model": "${env:OPENAI_MODEL:-mimo-v2.6-flash}",
|
||||
"timeout_seconds": "${env:ARTEMIS_STEP_SUMMARIZER_TIMEOUT_SECONDS:-25}",
|
||||
"prune_history_xml": true
|
||||
}
|
||||
},
|
||||
|
||||
@@ -113,22 +113,28 @@ class ScreenAwakeLease:
|
||||
}
|
||||
|
||||
@contextmanager
|
||||
def _mutex(self):
|
||||
def _mutex(self, *, wait_timeout_seconds: float | None = None):
|
||||
self.mutex_path.parent.mkdir(parents=True, exist_ok=True)
|
||||
started_at = time.monotonic()
|
||||
timeout = (
|
||||
self._MUTEX_TIMEOUT_SECONDS
|
||||
if wait_timeout_seconds is None
|
||||
else max(0.0, wait_timeout_seconds)
|
||||
)
|
||||
acquired = False
|
||||
while not acquired:
|
||||
try:
|
||||
fd = os.open(self.mutex_path, os.O_CREAT | os.O_EXCL | os.O_WRONLY)
|
||||
except FileExistsError:
|
||||
if time.monotonic() - started_at >= timeout:
|
||||
raise TimeoutError("Timed out acquiring the Artemis awake-lease mutex.")
|
||||
if self._path_is_stale(self.mutex_path):
|
||||
try:
|
||||
self.mutex_path.unlink(missing_ok=True)
|
||||
except OSError:
|
||||
pass
|
||||
continue
|
||||
if time.monotonic() - started_at >= self._MUTEX_TIMEOUT_SECONDS:
|
||||
raise TimeoutError("Timed out acquiring the Artemis awake-lease mutex.")
|
||||
else:
|
||||
continue
|
||||
time.sleep(self._MUTEX_POLL_SECONDS)
|
||||
else:
|
||||
try:
|
||||
@@ -274,10 +280,15 @@ class ScreenAwakeLease:
|
||||
def cleanup_unowned_references(self) -> bool:
|
||||
"""Drain legacy shell wake locks only when no live old host owns them."""
|
||||
try:
|
||||
with self._mutex():
|
||||
# Migration cleanup is optional. A busy owner must not delay every
|
||||
# queued task by the normal 10-second lease-acquisition deadline.
|
||||
with self._mutex(wait_timeout_seconds=1.0):
|
||||
if self._live_leases():
|
||||
return False
|
||||
return self._drain_references()
|
||||
except TimeoutError:
|
||||
logger.debug(f"Skipped optional wake-lock cleanup on {self.device_id}: mutex busy")
|
||||
return False
|
||||
except Exception as exc:
|
||||
logger.warning(f"Could not clean unowned screen wake locks on {self.device_id}: {exc}")
|
||||
return False
|
||||
@@ -95,9 +95,10 @@ def _configure_usb_stay_awake(device_id: str) -> str | None:
|
||||
if not _awake_enabled() or os.environ.get("ARTEMIS_CLOUD_MODE") == "1":
|
||||
return None
|
||||
|
||||
# Migration cleanup: previous Artemis versions used a persistent shell
|
||||
# wake lock. Drain it only after every live legacy owner has exited.
|
||||
ScreenAwakeLease(device_id).cleanup_unowned_references()
|
||||
# Migration cleanup belongs to the long-lived host. A queued task worker
|
||||
# must not wait on another process's optional legacy wake-lock cleanup.
|
||||
if os.environ.get("ARTEMIS_TASK_WORKER") != "1":
|
||||
ScreenAwakeLease(device_id).cleanup_unowned_references()
|
||||
|
||||
commands = (
|
||||
(
|
||||
|
||||
@@ -33,6 +33,7 @@
|
||||
"step_summarizer": {
|
||||
"enabled": "${env:ARTEMIS_STEP_SUMMARIZER_ENABLED:-true}",
|
||||
"model": "${env:OPENAI_MODEL:-mimo-v2.6-flash}",
|
||||
"timeout_seconds": "${env:ARTEMIS_STEP_SUMMARIZER_TIMEOUT_SECONDS:-25}",
|
||||
"prune_history_xml": true
|
||||
}
|
||||
},
|
||||
|
||||
@@ -0,0 +1,13 @@
|
||||
# ARTEMIS-Eapil 1.2.2
|
||||
|
||||
## 修复
|
||||
|
||||
- 任务报告区分实际执行失败与可恢复的诊断警告。屏幕唤醒锁清理超时、步骤视觉摘要重试不再被误写为任务或模型请求超时;真实终止异常仍会显示。
|
||||
- 旧屏幕唤醒锁清理遇到设备锁繁忙时快速跳过,避免队列任务因清理动作等待或连续失败。长驻服务负责后续清理。
|
||||
- Flash 步骤视觉摘要使用独立超时,默认 25 秒,可通过 `ARTEMIS_STEP_SUMMARIZER_TIMEOUT_SECONDS` 设置,不再占用主模型请求的 300 秒超时额度。
|
||||
|
||||
## 安装与验证
|
||||
|
||||
下载附件 `artemis-eapil-1.2.2-source.zip`,解压后运行 `start.bat`;国内网络使用 `start-cn.bat`。附件含精简 Git 仓库,后续可由启动脚本检查更新。升级后重启 ARTEMIS 服务、刷新网页并重新加载 AI 客户端的 MCP。
|
||||
|
||||
验证:Python 默认测试 2191 项通过、2 项跳过、8 项按标记排除;Ruff、质量基线和核心类型检查通过。两项真实模拟器 Flash 批量任务均完成;干净环境未复现原先的锁争用,锁繁忙与报告归因通过回归测试覆盖。
|
||||
+1
-1
@@ -14,7 +14,7 @@
|
||||
|
||||
[project]
|
||||
name = "artemis"
|
||||
version = "1.2.1"
|
||||
version = "1.2.2"
|
||||
description = "Autonomous AI Assistant for Mobile Automation"
|
||||
|
||||
authors = [
|
||||
|
||||
@@ -420,6 +420,33 @@ async def test_model_timeout_from_runner_log_reaches_failed_task_and_report(isol
|
||||
assert "超时" in reports.session_report(job["session_id"])["error"]
|
||||
|
||||
|
||||
def test_optional_timeout_warnings_are_not_reported_as_task_failure(tmp_path):
|
||||
(tmp_path / "stdout.log").write_text(
|
||||
"⚠ Could not clean unowned screen wake locks on emulator-5554: "
|
||||
"Timed out acquiring the Artemis awake-lease mutex.\n"
|
||||
"⚠ VisualStepSummarizer: Error generating summary for step 3: \n"
|
||||
"ℹ StepMemoryService: Retrying Step 3 (attempt 4) after 1.0s\n",
|
||||
encoding="utf-8",
|
||||
)
|
||||
assert reports.failure_reason(tmp_path, "failed", None) == (
|
||||
"任务未完成,运行日志中没有可提取的具体异常;请查看执行步骤。"
|
||||
)
|
||||
|
||||
(tmp_path / "stderr.log").write_text(
|
||||
"TimeoutError: model request timed out after 300 seconds\n", encoding="utf-8"
|
||||
)
|
||||
reason = reports.failure_reason(tmp_path, "failed", None)
|
||||
assert "model request timed out" in reason
|
||||
assert "awake-lease" not in reason
|
||||
|
||||
(tmp_path / "stderr.log").write_text(
|
||||
"DeviceBusyError: device queue reservation was cancelled\n", encoding="utf-8"
|
||||
)
|
||||
assert reports.failure_reason(tmp_path, "failed", None) == (
|
||||
"DeviceBusyError: device queue reservation was cancelled"
|
||||
)
|
||||
|
||||
|
||||
def test_reports_do_not_execute_formulas_or_invent_pass(isolated):
|
||||
batch = service.create_batch(payload())
|
||||
job = isolated.jobs(batch["id"])[0]
|
||||
|
||||
@@ -14,6 +14,7 @@
|
||||
|
||||
"""Unit tests for VisualStepSummarizer and Context Compressor in Flash profile."""
|
||||
|
||||
import asyncio
|
||||
from unittest.mock import ANY, AsyncMock, Mock, call
|
||||
from uuid import uuid4
|
||||
import pytest
|
||||
@@ -106,6 +107,29 @@ async def test_summarizer_retries_independently(mock_context):
|
||||
assert attempt_count == 2
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_visual_summary_uses_its_own_configured_timeout(mock_context):
|
||||
summarizer = VisualStepSummarizer(mock_context, retry_limit=0, timeout_seconds=0.01)
|
||||
|
||||
async def slow_response(_messages):
|
||||
await asyncio.sleep(1)
|
||||
|
||||
summarizer._llm = Mock()
|
||||
summarizer._llm.ainvoke = AsyncMock(side_effect=slow_response)
|
||||
summarizer.dispatch(
|
||||
step_number=1,
|
||||
action_name="click",
|
||||
action_args={"target": [100, 100]},
|
||||
pre_img_bytes=b"pre",
|
||||
post_img_bytes=b"post",
|
||||
exec_outcome="Clicked",
|
||||
)
|
||||
|
||||
await summarizer.flush()
|
||||
assert summarizer.has_failed(1)
|
||||
assert summarizer._llm.ainvoke.await_count == 1
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_summarizer_bounded_retry_marks_failed(mock_context):
|
||||
"""Persistent failures exit after 1 + retry_limit attempts with an explicit failed state."""
|
||||
|
||||
@@ -13,6 +13,8 @@
|
||||
# limitations under the License.
|
||||
|
||||
import json
|
||||
from pathlib import Path
|
||||
import time
|
||||
|
||||
import pytest
|
||||
|
||||
@@ -126,3 +128,30 @@ def test_migration_cleanup_never_drains_a_live_legacy_owner(monkeypatch):
|
||||
cleanup._drain_references = lambda: pytest.fail("must not drain a live owner")
|
||||
|
||||
assert cleanup.cleanup_unowned_references() is False
|
||||
|
||||
|
||||
def test_optional_cleanup_skips_a_busy_mutex_without_delaying_task_start(monkeypatch):
|
||||
owner = ScreenAwakeLease("device-123")
|
||||
owner.mutex_path.write_text(json.dumps(owner._payload()), encoding="utf-8")
|
||||
cleanup = ScreenAwakeLease("device-123")
|
||||
monkeypatch.setattr(cleanup, "_drain_references", lambda: pytest.fail("must not drain"))
|
||||
|
||||
started_at = time.monotonic()
|
||||
assert cleanup.cleanup_unowned_references() is False
|
||||
assert time.monotonic() - started_at < 2.0
|
||||
|
||||
|
||||
def test_unremovable_stale_mutex_still_obeys_deadline(monkeypatch):
|
||||
lease = ScreenAwakeLease("device-123")
|
||||
lease.mutex_path.write_text(json.dumps({"pid": 999999}), encoding="utf-8")
|
||||
original_unlink = Path.unlink
|
||||
|
||||
def refuse_mutex_unlink(path, *args, **kwargs):
|
||||
if path == lease.mutex_path:
|
||||
raise PermissionError("file is in use")
|
||||
return original_unlink(path, *args, **kwargs)
|
||||
|
||||
monkeypatch.setattr(Path, "unlink", refuse_mutex_unlink)
|
||||
with pytest.raises(TimeoutError, match="awake-lease mutex"):
|
||||
with lease._mutex(wait_timeout_seconds=0.1):
|
||||
pytest.fail("stale mutex must not be acquired")
|
||||
@@ -1,3 +1,4 @@
|
||||
import os
|
||||
from unittest.mock import MagicMock, patch
|
||||
|
||||
from artemis.runtime.awake_service import (
|
||||
@@ -37,6 +38,22 @@ def test_usb_policy_is_primary_when_android_reports_it_active(mock_run, lease_ty
|
||||
assert not any("KEYCODE_UNKNOWN" in command for command in commands)
|
||||
|
||||
|
||||
@patch.dict(os.environ, {"ARTEMIS_TASK_WORKER": "1"})
|
||||
@patch("artemis.runtime.awake_service.ScreenAwakeLease")
|
||||
@patch("artemis.runtime.awake_service.subprocess.run")
|
||||
def test_queued_worker_does_not_run_optional_legacy_cleanup(mock_run, lease_type):
|
||||
mock_run.side_effect = [
|
||||
completed(),
|
||||
completed(),
|
||||
completed(),
|
||||
completed("2\n"),
|
||||
completed(" mStayOn=true\n"),
|
||||
]
|
||||
|
||||
assert _configure_usb_stay_awake("device-123") == AWAKE_STRATEGY_USB
|
||||
lease_type.assert_not_called()
|
||||
|
||||
|
||||
@patch("artemis.runtime.awake_service.ScreenAwakeLease")
|
||||
@patch("artemis.runtime.awake_service.subprocess.run")
|
||||
def test_inactive_usb_policy_falls_back_to_effective_host_heartbeat(mock_run, _lease_type):
|
||||
|
||||
Reference in new issue
Block a user