agents Intermittent Call Instability After Initial Successful Testing

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:

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.
After a successful room join, approximately 20 seconds later, the logs show "room disconnected."
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. https://github.com/livekit/agents/issues/951 https://github.com/livekit/agents/issues/948

Thank you for your assistance!

Oct 18 '24 08:10 BaiMoHan

Which version of agents are you running?

Oct 21 '24 06:10 davidzhao

Which version of agents are you running?

My version is 0.10.1.

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?

Oct 21 '24 07:10 BaiMoHan

@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

Oct 24 '24 19:10 EpicWerf

@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.

Oct 25 '24 02:10 BaiMoHan

@BaiMoHan are you still seeing issues here after using the transport option?

Are the logs similar after applying this option?

Nov 02 '24 00:11 davidzhao

@BaiMoHan are you still seeing issues here after using the transport option?

Are the logs similar after applying this option?

Yes, it suddenly became normal and can perform STT smoothly now. The interesting part is, how did you know it was restored? Did you modify something?

Nov 04 '24 09:11 BaiMoHan

@BaiMoHan are you still seeing issues here after using the transport option?

Are the logs similar after applying this option?

However, it only works in v0.10.1. I tried to upgrade it into v0.11.0, it cannot work, cannot stt.

Nov 04 '24 09:11 BaiMoHan