MetaGPT icon indicating copy to clipboard operation
MetaGPT copied to clipboard
verified publisher icon geekan

Warnings and errors while trying to execute metagpt utility with local LLM

Open guilherme-argentino opened this issue 1 year ago • 4 comments

Bug description During some tests with MetaGPT's CLI, the system keeps retrying to call when some error occurs and then crashes. Sometimes it takes 10 to 20 minutes to occur, and on the other hand in less than 2 minutes it crashes

Environment information

$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 12 (bookworm)
Release:        12
Codename:       bookworm
  • LLM type and model name: miqu-1-70b.q5_K_M.gguf (miqudev/miqu-1-70b)
  • System version: Linux ai 6.1.0-17-amd64 # 1 SMP PREEMPT_DYNAMIC Debian 6.1.69-1 (2023-12-30) x86_64 GNU/Linux
  • Python version: 3.11
  • installation method: pip install metagpt

Screenshots or logs

2024-02-08 21:04:08.798 | WARNING  | metagpt.utils.repair_llm_raw_output:run_and_passon:235 - parse json from content inside [CONTENT][/CONTENT] failed at retry 1, try to fix it, exp: Invalid \escape: '_': line 13 column 48 (char 315)
2024-02-08 21:04:08.799 | INFO     | metagpt.utils.repair_llm_raw_output:repair_invalid_json:204 - repair_invalid_json, raw error: Invalid \escape: '_': line 13 column 48 (char 315)
2024-02-08 21:04:09.800 | WARNING  | metagpt.utils.repair_llm_raw_output:run_and_passon:235 - parse json from content inside [CONTENT][/CONTENT] failed at retry 2, try to fix it, exp: Invalid \escape: '_': line 13 column 36 (char 303)
2024-02-08 21:04:09.801 | INFO     | metagpt.utils.repair_llm_raw_output:repair_invalid_json:204 - repair_invalid_json, raw error: Invalid \escape: '_': line 13 column 36 (char 303)
2024-02-08 21:04:10.802 | WARNING  | metagpt.utils.repair_llm_raw_output:run_and_passon:235 - parse json from content inside [CONTENT][/CONTENT] failed at retry 3, try to fix it, exp: Invalid \escape: '_': line 13 column 36 (char 303)
2024-02-08 21:04:10.802 | INFO     | metagpt.utils.repair_llm_raw_output:repair_invalid_json:204 - repair_invalid_json, raw error: Invalid \escape: '_': line 13 column 36 (char 303)
2024-02-08 21:04:10.803 | ERROR    | metagpt.utils.common:log_it:434 - Finished call to 'metagpt.actions.action_node.ActionNode._aask_v1' after 246.955(s), this was the 6th time calling it. exp: RetryError[<Future at 0x7fd7d3342410 state=finished raised JSONDecodeError>]
2024-02-08 21:04:10.804 | WARNING  | metagpt.utils.common:wrapper:506 - There is a exception in role's execution, in order to resume, we delete the newest role communication message in the role's memory.
2024-02-08 21:04:10.817 | ERROR    | metagpt.utils.common:wrapper:488 - Exception occurs, start to serialize the project, exp:
Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 252, in py_scanstring
    char = _b[esc]
           ~~^^^^^
KeyError: '_'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/__init__.py", line 382, in __call__
    result = fn(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/repair_llm_raw_output.py", line 263, in retry_parse_json_text
    parsed_data = CustomDecoder(strict=False).decode(output)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
json.decoder.JSONDecodeError: Invalid \escape: '_': line 13 column 36 (char 303)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/_asyncio.py", line 50, in __call__
    result = await fn(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/action_node.py", line 273, in _aask_v1
    parsed_data = llm_output_postprocess(
                  ^^^^^^^^^^^^^^^^^^^^^^^
tenacity.RetryError: RetryError[<Future at 0x7fd7d3342410 state=finished raised JSONDecodeError>]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/common.py", line 497, in wrapper
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/roles/role.py", line 482, in run
    rsp = await self.react()
          ^^^^^^^^^^^^^^^^^^
tenacity.RetryError: RetryError[<Future at 0x7fd7d3342c90 state=finished raised RetryError>]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/common.py", line 483, in wrapper
    result = await func(self, *args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/team.py", line 133, in run
    await self.env.run()
Exception: Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 252, in py_scanstring
    char = _b[esc]
           ~~^^^^^
KeyError: '_'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/__init__.py", line 382, in __call__
    result = fn(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/repair_llm_raw_output.py", line 263, in retry_parse_json_text
    parsed_data = CustomDecoder(strict=False).decode(output)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 297, in decode
    return super().decode(s)
           ^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/json/decoder.py", line 337, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/json/decoder.py", line 353, in raw_decode
    obj, end = self.scan_once(s, idx)
               ^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 65, in scan_once
    return _scan_once(string, idx)
           ^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 36, in _scan_once
    return parse_object((string, idx + 1), strict, _scan_once, object_hook, object_pairs_hook, memo)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 164, in JSONObject
    value, end = scan_once(s, end)
                 ^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 38, in _scan_once
    return parse_array((string, idx + 1), _scan_once)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/json/decoder.py", line 230, in JSONArray
    value, end = scan_once(s, end)
                 ^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 38, in _scan_once
    return parse_array((string, idx + 1), _scan_once)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/json/decoder.py", line 230, in JSONArray
    value, end = scan_once(s, end)
                 ^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 34, in _scan_once
    return parse_string(string, idx + 1, strict, delimiter=nextchar)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/custom_decoder.py", line 255, in py_scanstring
    raise JSONDecodeError(msg, s, end)
json.decoder.JSONDecodeError: Invalid \escape: '_': line 13 column 36 (char 303)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/_asyncio.py", line 50, in __call__
    result = await fn(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/action_node.py", line 273, in _aask_v1
    parsed_data = llm_output_postprocess(
                  ^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/provider/postprocess/llm_output_postprocess.py", line 19, in llm_output_postprocess
    result = postprocess_plugin.run(output=output, schema=schema, req_key=req_key)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/provider/postprocess/base_postprocess_plugin.py", line 68, in run
    new_output = self.run_repair_llm_output(output=output, schema=schema, req_key=req_key)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/provider/postprocess/base_postprocess_plugin.py", line 32, in run_repair_llm_output
    parsed_data = self.run_retry_parse_json_text(content)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/provider/postprocess/base_postprocess_plugin.py", line 47, in run_retry_parse_json_text
    parsed_data = retry_parse_json_text(output=content)  # should use output=content
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/__init__.py", line 289, in wrapped_f
    return self(f, *args, **kw)
           ^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/__init__.py", line 379, in __call__
    do = self.iter(retry_state=retry_state)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/__init__.py", line 326, in iter
    raise retry_exc from fut.exception()
tenacity.RetryError: RetryError[<Future at 0x7fd7d3342410 state=finished raised JSONDecodeError>]

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/utils/common.py", line 497, in wrapper
    return await func(self, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/roles/role.py", line 482, in run
    rsp = await self.react()
          ^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/roles/role.py", line 450, in react
    rsp = await self._react()
          ^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/roles/role.py", line 429, in _react
    rsp = await self._act()  # 这个rsp是否需要publish_message？
          ^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/roles/role.py", line 358, in _act
    response = await self.rc.todo.run(self.rc.history)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/project_management.py", line 53, in run
    task_doc = await self._update_tasks(
               ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/project_management.py", line 79, in _update_tasks
    rsp = await self._run_new_tasks(context=system_design_doc.content)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/project_management.py", line 91, in _run_new_tasks
    node = await PM_NODE.fill(context, self.llm, schema)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/action_node.py", line 338, in fill
    return await self.simple_fill(schema=schema, mode=mode, timeout=timeout, exclude=exclude)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/metagpt/actions/action_node.py", line 303, in simple_fill
    content, scontent = await self._aask_v1(prompt, class_name, mapping, schema=schema, timeout=timeout)
                        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/_asyncio.py", line 88, in async_wrapped
    return await fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/_asyncio.py", line 47, in __call__
    do = self.iter(retry_state=retry_state)
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/opt/anaconda3/envs/myenv/lib/python3.11/site-packages/tenacity/__init__.py", line 326, in iter
    raise retry_exc from fut.exception()
tenacity.RetryError: RetryError[<Future at 0x7fd7d3342c90 state=finished raised RetryError>]

guilherme-argentino avatar Feb 09 '24 13:02 guilherme-argentino

Same here.

andrezaiats avatar Feb 09 '24 13:02 andrezaiats

Is it the same JSON decoding error? I've encountered the same issue. image image

Rchenyu avatar Feb 14 '24 04:02 Rchenyu

@guilherme-argentino @andrezaiats what's the version of metagpt and the cli command (like mtagpt 'xxx') ?

better629 avatar Mar 02 '24 09:03 better629

@guilherme-argentino failed at retry 1, try to fix it, exp: Invalid \escape: '_': line 13 column 48 (char 315) implies that the large model returned content is not in JSON format, while repair_invalid_json:204 - repair_invalid_json, raw error: Invalid \escape: '_': line 13 column 48 (char 315) indicates that Metagpt attempted to repair this JSON package, but the repair failed. I suggest you add some logs in _achat_completion_stream and _achat_completion, where the large model returns, and check what the large model returns. The access classes for the large models are all in metagpt/provider.

iorisa avatar Mar 04 '24 08:03 iorisa