This message was deleted LiveKit Community #helpdesk

Join Slack

This message was deleted.

# helpdesk

steep-balloon-41261

12/18/2023, 5:21 PM

This message was deleted.

👀 1

crooked-knife-24080

12/18/2023, 5:22 PM

I don't think this is really affecting us aside from adding a bunch of exceptions to our logs. Just thought you'd like to know about it!

crooked-knife-24080

12/18/2023, 5:25 PM

(This happens on lines 251, 256, and 403 from 354)

magnificent-art-43333

12/18/2023, 5:34 PM

cc @boundless-energy-78552

boundless-energy-78552

12/18/2023, 11:20 PM

Interesting, going to take a look

boundless-energy-78552

12/19/2023, 4:14 AM

Can you send the exception you were seeing?

crooked-knife-24080

12/19/2023, 4:48 PM

Sure. Here's what I stitched together from 2023-12-18 092330.662 (pacific) in our logs.

Copy code

ERROR [root] [room.py:227] - error running user callback for track_published: room_handle: 2647771

track_published {
  participant_sid: "PA_FHh6X9Bf6Khc"
  publication {
    handle {
      id: 2649664
    }
    info {
      sid: "TR_AM9EdjtV9ye7Z7"
      name: "audio"
      kind: KIND_AUDIO
      source: SOURCE_MICROPHONE
      mime_type: "audio/red"
      remote: true
    }
  }
}

Traceback (most recent call last):
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 225, in _listen_task
    self._on_room_event(event.room_event)
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 259, in _on_room_event
    rparticipant = self.participants[event.track_published.participant_sid]

KeyError: 'PA_FHh6X9Bf6Khc'

ERROR [root] [room.py:227] - error running user callback for track_subscribed: room_handle: 2647771

track_subscribed {
  participant_sid: "PA_FHh6X9Bf6Khc"
  track {
    handle {
      id: 2649666
    }
    info {
      sid: "TR_AM9EdjtV9ye7Z7"
      name: "audio"
      kind: KIND_AUDIO
      stream_state: STATE_ACTIVE
      remote: true
    }
  }
}

Traceback (most recent call last):
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 225, in _listen_task
    self._on_room_event(event.room_event)
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 272, in _on_room_event
    rparticipant = self.participants[event.track_subscribed.participant_sid]

KeyError: 'PA_FHh6X9Bf6Khc'

powerful-garage-56223

12/20/2023, 7:47 PM

Hey @crooked-knife-24080 - i’m trying to reproduce this and not having any luck. Have you continued to see this? Have you gained any intuition on when it happens?

crooked-knife-24080

12/20/2023, 8:53 PM

We haven't seen it in the same quantity, but it still happens occasionally. We're also logging every event from the room now. Here's a snippet from a recent exception:

crooked-knife-24080

12/20/2023, 8:54 PM

And the stack:

Copy code

Traceback (most recent call last):
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 225, in _listen_task
    self._on_room_event(event.room_event)
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 354, in _on_room_event
    participant = self._retrieve_participant(sid)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 403, in _retrieve_participant
    return self.participants[sid]
           ~~~~~~~~~~~~~~~~~^^^^^
KeyError: 'PA_7ZQTn2sF8mYh'

boundless-energy-78552

12/21/2023, 2:42 PM

Just found the cause, I’m going to work on a fix

🙏 2

bulky-minister-73741

12/21/2023, 6:16 PM

awesome, thanks!

crooked-knife-24080

01/29/2024, 5:22 PM

Hey @boundless-energy-78552, has this been fixed? We're now on version 0.8 but got paged over the weekend because of a storm of similar errors. Here are some relevant logs from the event:

Copy code

Jan 27 22:45:22.197
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:45:22.189
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:45:12.174
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:45:02.152
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:45:02.145
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:44:52.141
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:44:52.136
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:44:42.118
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:44:32.113
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:44:32.104
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:44:22.077
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:44:11.784
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:44:11.773
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:44:01.769
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:44:01.761
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:43:01.680
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:42:51.685
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:42:51.662
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:42:31.638
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:42:21.622
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:42:21.618
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:42:11.612
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:42:01.611
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:42:01.607
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:41:51.602
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:41:41.596
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:41:41.580
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:41:31.599
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_GOOD }

Jan 27 22:41:31.568
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" }

Jan 27 22:40:09.819
fixie-voice
error running user callback for connection_quality_changed: room_handle: 418508 connection_quality_changed { participant_sid: "PA_6KtecWzohnHM" quality: QUALITY_EXCELLENT }

Jan 27 22:39:59.917
fixie-voice
[livekit room] reconnected

Jan 27 22:39:59.916
fixie-voice
[livekit room] connection_state_changed

Jan 27 22:39:59.915
fixie-voice
error running user callback for local_track_published: room_handle: 418508 local_track_published { track_sid: "TR_AMfUgyQ7pXdziG" }

Jan 27 22:39:59.889
fixie-voice
[livekit room] local_track_unpublished

Jan 27 22:39:30.058
fixie-voice
[livekit room] reconnecting

Jan 27 22:39:30.057
fixie-voice
[livekit room] connection_state_changed

Jan 27 22:39:30.055
fixie-voice
Connection quality for worker is now: QUALITY_GOOD (1)

Jan 27 22:39:30.055
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:39:30.054
fixie-voice
Connection quality for worker is now: QUALITY_POOR (0)

Jan 27 22:39:30.050
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:39:30.048
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:39:30.048
fixie-voice
Connection quality for worker is now: QUALITY_GOOD (1)

Jan 27 22:39:30.047
fixie-voice
[livekit room] reconnected

Jan 27 22:39:30.046
fixie-voice
[livekit room] connection_state_changed

Jan 27 22:38:49.561
fixie-voice
[livekit room] reconnecting

Jan 27 22:38:49.548
fixie-voice
[livekit room] connection_state_changed

Jan 27 22:38:29.561
fixie-voice
Connection quality for worker is now: QUALITY_EXCELLENT (2)

Jan 27 22:38:29.558
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:38:19.485
fixie-voice
Connection quality for worker is now: QUALITY_GOOD (1)

Jan 27 22:38:19.485
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:38:09.517
fixie-voice
Connection quality for worker is now: QUALITY_POOR (0)

Jan 27 22:38:09.516
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:38:09.493
fixie-voice
[livekit room] connection_quality_changed

Jan 27 22:38:09.493
fixie-voice
Connection quality for worker is now: QUALITY_GOOD (1)

Jan 27 22:37:59.569
fixie-voice
Connection quality for worker is now: QUALITY_POOR (0)

and the stack is similar to before:

Copy code

Traceback (most recent call last):
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 235, in _listen_task
    self._on_room_event(event.room_event)
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 364, in _on_room_event
    participant = self._retrieve_participant(sid)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/.venv/lib/python3.11/site-packages/livekit/rtc/room.py", line 415, in _retrieve_participant
    return self.participants[sid]
           ~~~~~~~~~~~~~~~~~^^^^^
KeyError: 'PA_6KtecWzohnHM'

LMK if it'd be helpful to track this in an issue instead!

boundless-energy-78552

01/29/2024, 7:59 PM

Hey, this is still not fixed, we have plan to fix it on the following weeks. This should not impact how the application behaves

crooked-knife-24080

01/30/2024, 4:21 PM

Cool, thanks for confirming. I've suppressed this on our end. 🙂

👍 1

Open in Slack

Previous Next