Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Intermittent Call Instability After Initial Successful Testing #952

Open
BaiMoHan opened this issue Oct 18, 2024 · 4 comments
Open

Intermittent Call Instability After Initial Successful Testing #952

BaiMoHan opened this issue Oct 18, 2024 · 4 comments

Comments

@BaiMoHan
Copy link

I have developed my agent code based on livekit-examples/voice-pipeline-agent-python and implemented the frontend using livekit/agents-playground. On October 16th, I successfully established a functional call flow. I can confirm that on the morning of October 17th, we conducted multiple successful call tests. However, by the evening of the 17th, I noticed that the call stability had deteriorated.

The issues manifest in the following ways:

  1. Frequent fluctuations where speech is not recognized after a successful connection. The waveforms are visible on the frontend, but there are no changes in the backend logs. Occasionally, after a successful call, the system returns to normal state. I am uncertain if this is related to the livekit.cloud forwarding or any adjustments made.

  2. After a successful room join, approximately 20 seconds later, the logs show "room disconnected."

  3. The rtc_engine emits a warning stating "stream closed," but no other obvious errors are logged.

I have previously raised a few related issues for further reference.
#951
#948

Thank you for your assistance!

@davidzhao
Copy link
Member

Which version of agents are you running?

@BaiMoHan
Copy link
Author

Which version of agents are you running?

My version is 0.10.1.
image

After I upgraded my plan, it started working. I haven't changed any code since last Friday. It's too strange. Are there any limitations for the free plan?

@EpicWerf
Copy link

@BaiMoHan is it still working fine after upgrading your plan?

I think it may be related to the issue I brought up in this slack thread.

At the bottom of my thread you'll see it seemed to be working fine, but earlier this week it started happening to me again.

My experience is the agent leaves the room, and I occasionally see error logs similar to what you see. Here are some that I think are related:

{"message": "livekit::rtc_engine:628:livekit::rtc_engine - resuming connection... attempt: 0", "level": "ERROR", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:08.997493+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"signal client closed: \\\"stream closed\\\"\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:08.997061+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"server request to leave\" StateMismatch Resume", "level": "WARNING", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:08.996946+00:00"}
{"message": "initializing process", "level": "INFO", "name": "livekit.agents", "pid": 4835, "timestamp": "2024-10-24T03:58:13.818917+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"signal client closed: \\\"stream closed\\\"\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:26.991298+00:00"}
{"message": "job exiting", "level": "INFO", "name": "livekit.agents", "reason": "", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:26.985796+00:00"}
{"message": "livekit::rtc_engine::rtc_session:549:livekit::rtc_engine::rtc_session - Subscriber pc state failed", "level": "ERROR", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:37.612272+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"pc_state failed\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:37.612498+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"server request to leave\" StateMismatch Resume", "level": "WARNING", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:36.237074+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"signal client closed: \\\"stream closed\\\"\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:36.237207+00:00"}
{"message": "livekit::rtc_engine:628:livekit::rtc_engine - resuming connection... attempt: 0", "level": "ERROR", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:36.237296+00:00"}
{"message": "livekit::rtc_engine:630:livekit::rtc_engine - resuming connection failed: connection error: wait_pc_connection timed out", "level": "ERROR", "name": "livekit", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:31.729311+00:00"}
{"message": "livekit::rtc_engine:610:livekit::rtc_engine - restarting connection... attempt: 1", "level": "ERROR", "name": "livekit", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:31.729511+00:00"}
{"message": "error running user callback for local_track_published: room_handle: 3\nlocal_track_published {\n  track_sid: \"TR_AMUnYrE8Nyhpb2\"\n}\nTraceback (most recent call last):\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 426, in _listen_task\n    self._on_room_event(event.room_event)\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 452, in _on_room_event\n    lpublication = self.local_participant.track_publications[sid]\n                   ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^\nKeyError: 'TR_AMUnYrE8Nyhpb2'", "level": "ERROR", "name": "root", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:32.134328+00:00"}
{"message": "error running user callback for local_track_published: room_handle: 3\nlocal_track_published {\n  track_sid: \"TR_AMBkrEHmdwhzui\"\n}\nTraceback (most recent call last):\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 426, in _listen_task\n    self._on_room_event(event.room_event)\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 452, in _on_room_event\n    lpublication = self.local_participant.track_publications[sid]\n                   ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^\nKeyError: 'TR_AMBkrEHmdwhzui'", "level": "ERROR", "name": "root", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:32.157765+00:00"}
{"message": "job exiting", "level": "INFO", "name": "livekit.agents", "reason": "", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:49:02.629515+00:00"}
{"message": "job exiting", "level": "INFO", "name": "livekit.agents", "reason": "", "pid": 3935, "job_id": "AJ_Ac45JTW2Cebb", "timestamp": "2024-10-24T01:51:33.621241+00:00"}

I was on agents version 0.10.1; I'm downgrading to 0.10.0 to see if anything changes

@BaiMoHan
Copy link
Author

BaiMoHan commented Oct 25, 2024

@BaiMoHan is it still working fine after upgrading your plan?

I think it may be related to the issue I brought up in this slack thread.

At the bottom of my thread you'll see it seemed to be working fine, but earlier this week it started happening to me again.

My experience is the agent leaves the room, and I occasionally see error logs similar to what you see. Here are some that I think are related:

{"message": "livekit::rtc_engine:628:livekit::rtc_engine - resuming connection... attempt: 0", "level": "ERROR", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:08.997493+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"signal client closed: \\\"stream closed\\\"\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:08.997061+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"server request to leave\" StateMismatch Resume", "level": "WARNING", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:08.996946+00:00"}
{"message": "initializing process", "level": "INFO", "name": "livekit.agents", "pid": 4835, "timestamp": "2024-10-24T03:58:13.818917+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"signal client closed: \\\"stream closed\\\"\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:26.991298+00:00"}
{"message": "job exiting", "level": "INFO", "name": "livekit.agents", "reason": "", "pid": 203, "job_id": "AJ_55kWdshYaxXK", "timestamp": "2024-10-24T03:58:26.985796+00:00"}
{"message": "livekit::rtc_engine::rtc_session:549:livekit::rtc_engine::rtc_session - Subscriber pc state failed", "level": "ERROR", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:37.612272+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"pc_state failed\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:37.612498+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"server request to leave\" StateMismatch Resume", "level": "WARNING", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:36.237074+00:00"}
{"message": "livekit::rtc_engine:410:livekit::rtc_engine - received session close: \"signal client closed: \\\"stream closed\\\"\" UnknownReason Resume", "level": "WARNING", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:36.237207+00:00"}
{"message": "livekit::rtc_engine:628:livekit::rtc_engine - resuming connection... attempt: 0", "level": "ERROR", "name": "livekit", "pid": 5785, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:47:36.237296+00:00"}
{"message": "livekit::rtc_engine:630:livekit::rtc_engine - resuming connection failed: connection error: wait_pc_connection timed out", "level": "ERROR", "name": "livekit", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:31.729311+00:00"}
{"message": "livekit::rtc_engine:610:livekit::rtc_engine - restarting connection... attempt: 1", "level": "ERROR", "name": "livekit", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:31.729511+00:00"}
{"message": "error running user callback for local_track_published: room_handle: 3\nlocal_track_published {\n  track_sid: \"TR_AMUnYrE8Nyhpb2\"\n}\nTraceback (most recent call last):\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 426, in _listen_task\n    self._on_room_event(event.room_event)\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 452, in _on_room_event\n    lpublication = self.local_participant.track_publications[sid]\n                   ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^\nKeyError: 'TR_AMUnYrE8Nyhpb2'", "level": "ERROR", "name": "root", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:32.134328+00:00"}
{"message": "error running user callback for local_track_published: room_handle: 3\nlocal_track_published {\n  track_sid: \"TR_AMBkrEHmdwhzui\"\n}\nTraceback (most recent call last):\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 426, in _listen_task\n    self._on_room_event(event.room_event)\n  File \"/home/appuser/.local/lib/python3.11/site-packages/livekit/rtc/room.py\", line 452, in _on_room_event\n    lpublication = self.local_participant.track_publications[sid]\n                   ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^\nKeyError: 'TR_AMBkrEHmdwhzui'", "level": "ERROR", "name": "root", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:48:32.157765+00:00"}
{"message": "job exiting", "level": "INFO", "name": "livekit.agents", "reason": "", "pid": 5852, "job_id": "AJ_vRYt78Ht5u7N", "timestamp": "2024-10-24T01:49:02.629515+00:00"}
{"message": "job exiting", "level": "INFO", "name": "livekit.agents", "reason": "", "pid": 3935, "job_id": "AJ_Ac45JTW2Cebb", "timestamp": "2024-10-24T01:51:33.621241+00:00"}

I was on agents version 0.10.1; I'm downgrading to 0.10.0 to see if anything changes

I have encountered issues with your first and second logs. After upgrading my plan, the logs appear to be normal, but the service is not functioning correctly. I reached out to support, where Mike advised me on adjusting the connection options. However, his recommendations did not prove to be effective. My current issue is that the Speech to Text (STT) function is not consistently working properly. I can hear the user's speech from the Egress, but in the front and backend, the STT does not seem to be running. As of now, I have not received a response from the support team.
image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants