agents icon indicating copy to clipboard operation
agents copied to clipboard

Deepgram timeout causes agent to stop responding

Open ForTheYin opened this issue 1 year ago • 3 comments

How to reproduce

Not able to reproduce consistently, but it happens occasionally with the example code provided in https://github.com/livekit/agents/blob/main/examples/voice-assistant/minimal_assistant.py

Might be able to trigger it locally if you can block deepgram through the OS.

Setup

Python 3.12.4 on macOS 14.6.1 M1 ARM64

requirements.txt.lock

aiodns==3.2.0
aiohappyeyeballs==2.4.0
aiohttp==3.10.5
aiohttp-retry==2.8.3
aiosignal==1.3.1
amqp==5.2.0
annotated-types==0.7.0
anyio==4.4.0
asgiref==3.8.1
attrs==24.2.0
autobahn==24.4.2
Automat==24.8.1
av==13.0.0
billiard==4.2.0
black==24.4.2
boto3==1.35.2
botocore==1.35.22
celery==5.4.0
certifi==2024.8.30
cffi==1.17.1
channels==4.1.0
channels-redis==4.1.0
charset-normalizer==3.3.2
click==8.1.7
click-didyoumean==0.3.1
click-plugins==1.1.1
click-repl==0.3.0
coloredlogs==15.0.1
constantly==23.10.4
cryptography==43.0.1
daphne==4.1.2
distro==1.9.0
Django==5.0.6
django-celery-results==2.5.1
django-ninja==1.2.1
flatbuffers==24.3.25
frozenlist==1.4.1
h11==0.14.0
httpcore==1.0.5
httpx==0.27.2
humanfriendly==10.0
hyperlink==21.0.0
idna==3.10
incremental==24.7.2
jiter==0.5.0
jmespath==1.0.1
kombu==5.4.1
livekit==0.14.0
livekit-agents==0.8.10
livekit-api==0.7.0
livekit-plugins-deepgram==0.6.6
livekit-plugins-elevenlabs==0.7.3
livekit-plugins-openai==0.8.1
livekit-plugins-silero==0.6.4
livekit-protocol==0.6.0
mpmath==1.3.0
msgpack==1.1.0
multidict==6.1.0
mypy-extensions==1.0.0
numpy==2.1.1
onnxruntime==1.19.2
openai==1.46.0
packaging==24.1
pathspec==0.12.1
pillow==10.3.0
platformdirs==4.3.6
prompt_toolkit==3.0.47
protobuf==5.28.2
psutil==5.9.8
pyasn1==0.6.1
pyasn1_modules==0.4.1
pybase64==1.4.0
pycares==4.4.0
pycparser==2.22
pydantic==2.9.2
pydantic_core==2.23.4
PyJWT==2.9.0
pyOpenSSL==24.2.1
python-dateutil==2.9.0.post0
redis==5.0.7
requests==2.32.3
s3transfer==0.10.2
service-identity==24.1.0
setuptools==75.1.0
six==1.16.0
sniffio==1.3.1
sqlparse==0.5.1
sympy==1.13.3
tqdm==4.66.5
twilio==9.2.3
Twisted==24.7.0
txaio==23.1.1
types-protobuf==4.25.0.20240417
typing_extensions==4.12.2
tzdata==2024.1
urllib3==2.2.3
uuid7==0.1.0
vine==5.1.0
watchfiles==0.24.0
wcwidth==0.2.13
websockets==13.0.1
yarl==1.11.1
zope.interface==7.0.3

Logs

2024-09-19 01:58:32,080 - WARNING livekit.agents - Running <Task pending name='Task-33' coro=<_stream_synthesis_task() running at ~/env/lib/python3.12/site-packages/livekit/agents/utils/log.py:16> cb=[AgentOutput._synthesize_task.<locals>.<lambda>() at ~/env/lib/python3.12/site-packages/livekit/agents/voice_assistant/agent_output.py:164, _wait.<locals>._on_completion() at /usr/local/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/asyncio/tasks.py:534]> took too long: 15.24 seconds {"pid": 94165, "job_id": "AJ_bGsA4AR6ykdb"}
2024-09-19 01:58:32,087 - ERROR livekit.agents - Error in _read_ipc_task
Traceback (most recent call last):
  File "~/env/lib/python3.12/site-packages/livekit/agents/utils/log.py", line 16, in async_fn_logs
    return await fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "~/env/lib/python3.12/site-packages/livekit/agents/ipc/proc_main.py", line 195, in _read_ipc_task
    no_msg_timeout.reset()
  File "~/env/lib/python3.12/site-packages/livekit/agents/utils/aio/sleep.py", line 34, in reset
    raise SleepFinished
livekit.agents.utils.aio.sleep.SleepFinished {"pid": 94165, "job_id": "AJ_bGsA4AR6ykdb"}
worker process is not responding.. worker crashed?
2024-09-19 01:58:32,094 - WARNING livekit.plugins.deepgram - deepgram connection failed, retrying in 0s
Traceback (most recent call last):
  File "~/env/lib/python3.12/site-packages/livekit/plugins/deepgram/stt.py", line 334, in _run_ws
    await asyncio.gather(*tasks)
  File "~/env/lib/python3.12/site-packages/livekit/plugins/deepgram/stt.py", line 316, in recv_task
    raise Exception("deepgram connection closed unexpectedly")
Exception: deepgram connection closed unexpectedly

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "~/env/lib/python3.12/site-packages/livekit/plugins/deepgram/stt.py", line 243, in _run
    await self._run_ws(ws)
  File "~/env/lib/python3.12/site-packages/livekit/plugins/deepgram/stt.py", line 336, in _run_ws
    await utils.aio.gracefully_cancel(*tasks)
  File "~/env/lib/python3.12/site-packages/livekit/agents/utils/aio/__init__.py", line 16, in gracefully_cancel
    await asyncio.gather(*futures)
  File "~/env/lib/python3.12/site-packages/livekit/plugins/deepgram/stt.py", line 297, in send_task
    await ws.send_bytes(frame.data.tobytes())
  File "~/env/lib/python3.12/site-packages/aiohttp/client_ws.py", line 230, in send_bytes
    await self._writer.send(data, binary=True, compress=compress)
  File "~/env/lib/python3.12/site-packages/aiohttp/http_websocket.py", line 724, in send
    await self._send_frame(message, WSMsgType.BINARY, compress)
  File "~/env/lib/python3.12/site-packages/aiohttp/http_websocket.py", line 626, in _send_frame
    raise ConnectionResetError("Cannot write to closing transport")
ConnectionResetError: Cannot write to closing transport {"pid": 94165, "job_id": "AJ_bGsA4AR6ykdb"}
Process job_proc:
Traceback (most recent call last):
  File "/usr/local/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/multiprocessing/process.py", line 314, in _bootstrap
    self.run()
  File "/usr/local/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)
  File "~/env/lib/python3.12/site-packages/livekit/agents/ipc/proc_main.py", line 272, in main
    loop.run_until_complete(main_task)
  File "/usr/local/Cellar/[email protected]/3.12.4/Frameworks/Python.framework/Versions/3.12/lib/python3.12/asyncio/base_events.py", line 687, in run_until_complete
    return future.result()
           ^^^^^^^^^^^^^^^
  File "~/env/lib/python3.12/site-packages/livekit/agents/ipc/proc_main.py", line 233, in _async_main
    await utils.aio.gracefully_cancel(read_task, health_check_task)
  File "~/env/lib/python3.12/site-packages/livekit/agents/utils/aio/__init__.py", line 16, in gracefully_cancel
    await asyncio.gather(*futures)
  File "~/env/lib/python3.12/site-packages/livekit/agents/utils/log.py", line 16, in async_fn_logs
    return await fn(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "~/env/lib/python3.12/site-packages/livekit/agents/ipc/proc_main.py", line 195, in _read_ipc_task
    no_msg_timeout.reset()
  File "~/env/lib/python3.12/site-packages/livekit/agents/utils/aio/sleep.py", line 34, in reset
    raise SleepFinished
livekit.agents.utils.aio.sleep.SleepFinished

ForTheYin avatar Sep 19 '24 02:09 ForTheYin

Seeing the same issue.

AphinityApp avatar Sep 21 '24 22:09 AphinityApp

#me_to

yehuda-margolis avatar Oct 13 '24 08:10 yehuda-margolis

It seems like the job process cannot communicate with the worker process. worker process is not responding.. worker crashed?

I don't think it is related to deepgram. Maybe the worker process crashed or the event loop is blocked by a long-running operation?

theomonnom avatar Oct 16 '24 01:10 theomonnom

same here

xjasonsong avatar Nov 19 '24 07:11 xjasonsong

is there a workaround to fix this issue? facing the same issue in python agent.py dev mode when the participant left, leaving agent in the idle state for the long time (~1hr) and deepgram connection is closed.

Logs:

2024-12-24 22:41:17,695 - DEBUG livekit.agents.pipeline - received user transcript {"user_transcript": "Um, I don't wanna take the", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:21,207 - DEBUG livekit.agents.pipeline - validated agent reply {"speech_id": "83ab85891902", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:21,436 - DEBUG livekit.agents.pipeline - received user transcript {"user_transcript": "black athletic short sleeve tee, so please throw it", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:21,440 - DEBUG livekit.agents.pipeline - skipping validation, agent is speaking and does not allow interruptions {"speech_id": "83ab85891902", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:22,548 - DEBUG livekit.agents.pipeline - speech playout started {"speech_id": "83ab85891902", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:23,969 - DEBUG livekit.agents.pipeline - speech playout finished {"speech_id": "83ab85891902", "interrupted": false, "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:23,972 - DEBUG livekit.agents.pipeline - committed agent speech {"agent_transcript": " Here\u2019s the updated recap of the products you chose:    1. **Sport Court 92** (P040) - Red and black sneakers with a sturdy design, suitable for both men and women. 2. **Knit Short Pants** (P014) - Blue knit short pants, designed for men, offering a casual style. 3. **Grey Hooded Pullover** (P061) - Cozy and stylish pullover designed for men, perfect for indoor activities. If you need any further assistance or have more questions, just let me know!", "interrupted": false, "speech_id": "83ab85891902", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:38,372 - DEBUG livekit.agents.pipeline - received user transcript {"user_transcript": "Okay. I think that's enough for today. Thank you", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:39,789 - DEBUG livekit.agents.pipeline - received user transcript {"user_transcript": "for your assistance, and goodbye.", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:40,166 - DEBUG livekit.agents.pipeline - validated agent reply {"speech_id": "046c1a0d18de", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:41,552 - DEBUG livekit.agents.pipeline - speech playout started {"speech_id": "046c1a0d18de", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:41,991 - DEBUG livekit.agents.pipeline - speech playout finished {"speech_id": "046c1a0d18de", "interrupted": false, "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:41,992 - DEBUG livekit.agents.pipeline - committed agent speech {"agent_transcript": " You're welcome! I'm glad I could assist you. If you have any more questions in the future or need help with anything else, feel free to reach out. Have a great day and goodbye!", "interrupted": false, "speech_id": "046c1a0d18de", "pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 22:41:52,991 - DEBUG luna-worker - Participant disconnected: python-client {"pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}
2024-12-24 23:42:03,381 - ERROR asyncio - _GatheringFuture exception was never retrieved
future: <_GatheringFuture finished exception=Exception('deepgram connection closed unexpectedly')>
Traceback (most recent call last):
  File "/usr/local/lib/python3.12/site-packages/livekit/plugins/deepgram/stt.py", line 474, in recv_task
    raise Exception("deepgram connection closed unexpectedly")
Exception: deepgram connection closed unexpectedly {"pid": 17, "job_id": "AJ_92Wh5NCQ2sjR"}

fhrzn avatar Dec 25 '24 06:12 fhrzn

This has been fixed in #1291

davidzhao avatar Dec 25 '24 08:12 davidzhao

you can use main as a workaround. we'll get a new version released in the next day or so

davidzhao avatar Dec 25 '24 08:12 davidzhao