2727
2828import asyncio
2929import logging
30+ from os import altsep
3031import select
3132import socket
3233import struct
6061MISSING = utils .MISSING
6162SocketReaderCallback = Callable [[bytes ], Any ]
6263_log = logging .getLogger (__name__ )
64+ _recv_log = logging .getLogger ('discord.voice.receiver' )
6365
6466
6567class SocketReader (threading .Thread ):
@@ -84,6 +86,7 @@ def __init__(
8486 self ._end : threading .Event = threading .Event ()
8587 self ._idle_paused : bool = True
8688 self ._started : threading .Event = threading .Event ()
89+ self ._warned_wait : bool = False
8790
8891 def is_running (self ) -> bool :
8992 return self ._started .is_set ()
@@ -152,9 +155,16 @@ def run(self) -> None:
152155 def _do_run (self ) -> None :
153156 while not self ._end .is_set ():
154157 if not self ._running .is_set ():
158+ if not self ._warned_wait :
159+ _log .warning ('Socket reader %s is waiting to be set as running' , self .name )
160+ self ._warned_wait = True
155161 self ._running .wait ()
156162 continue
157163
164+ if self ._warned_wait :
165+ _log .info ('Socket reader %s was set as running' , self .name )
166+ self ._warned_wait = False
167+
158168 try :
159169 readable , _ , _ = select .select ([self .state .socket ], [], [], 30 )
160170 except (ValueError , TypeError , OSError ) as e :
@@ -234,19 +244,20 @@ def __init__(
234244 self ._started : threading .Event = threading .Event ()
235245 self ._running : threading .Event = threading .Event ()
236246 self ._end : threading .Event = threading .Event ()
247+ self ._warned_queue : bool = False
237248
238249 self .decode_queue : deque [RawData ] = deque ()
239250 self .decoders : dict [int , opus .Decoder ] = {}
240251
241252 self ._end : threading .Event = threading .Event ()
242253
243254 def decode (self , frame : RawData ) -> None :
244- _log .debug ('Decoding frame %s' , frame )
245255 if not isinstance (frame , RawData ):
246256 raise TypeError (
247257 f"expected a RawData object, got { frame .__class__ .__name__ } "
248258 )
249259 self .decode_queue .append (frame )
260+ _log .debug ('Added frame %s to decode queue' , frame )
250261
251262 def is_running (self ) -> bool :
252263 return self ._started .is_set ()
@@ -300,17 +311,28 @@ def get_decoder(self, ssrc: int) -> opus.Decoder:
300311
301312 def _do_run (self ) -> None :
302313 while not self ._end .is_set ():
303- if not self ._running .is_set ():
304- self ._running .wait ()
314+ if not self .decode_queue :
315+ if not self ._warned_queue :
316+ _recv_log .warning ('No decode queue found, waiting' )
317+ self ._warned_queue = True
318+
319+ time .sleep (0.01 )
305320 continue
306321
322+ if self ._warned_queue :
323+ _recv_log .info ('Queue was filled' )
324+ self ._warned_queue = False
325+
307326 try :
308327 data = self .decode_queue .popleft ()
309328 except IndexError :
310329 continue
311330
331+ _recv_log .debug ('Popped %s from the decode queue' , data )
332+
312333 try :
313334 if data .decrypted_data is None :
335+ _log .warning ('Frame %s has no decrypted data, skipping' , data )
314336 continue
315337 else :
316338 data .decoded_data = self .get_decoder (data .ssrc ).decode (
@@ -390,12 +412,19 @@ def start_record_socket(self) -> None:
390412 return
391413 if self ._voice_recv_socket .is_running ():
392414 return
415+
416+ if not self ._decoder_thread .is_running ():
417+ self ._decoder_thread .start ()
418+
393419 self ._voice_recv_socket .start ()
394420
395421 def stop_record_socket (self ) -> None :
396422 if self ._voice_recv_socket .is_running ():
397423 self ._voice_recv_socket .stop ()
398424
425+ if self ._decoder_thread .is_running ():
426+ self ._decoder_thread .stop ()
427+
399428 for cb , args in self .recording_done_callbacks :
400429 task = self .loop .create_task (cb (* args ))
401430 self .__sink_dispatch_task_set .add (task )
@@ -408,7 +437,7 @@ def stop_record_socket(self) -> None:
408437 self .sinks .clear ()
409438
410439 def handle_voice_recv_packet (self , packet : bytes ) -> None :
411- _log .debug ('Handling voice packet %s' , packet )
440+ _recv_log .debug ('Handling voice packet %s' , packet )
412441 if packet [1 ] != 0x78 :
413442 # We should ignore any payload types we do not understand
414443 # Ref: RFC 3550 5.1 payload type
@@ -418,14 +447,17 @@ def handle_voice_recv_packet(self, packet: bytes) -> None:
418447 return
419448
420449 if self .paused_recording ():
450+ _log .debug ('Ignoring packet %s because recording is stopped' , packet )
421451 return
422452
423453 data = RawData (packet , self .client )
424454
425- if data .decrypted_data != opus .OPUS_SILENCE :
455+ if data .decrypted_data == opus .OPUS_SILENCE :
456+ _log .debug ('Ignoring packet %s because it is an opus silence frame' , data )
426457 return
427458
428459 self ._decoder_thread .decode (data )
460+ _recv_log .debug ('Submitted frame %s to decoder thread' , data )
429461
430462 def is_first_packet (self ) -> bool :
431463 return not self .user_voice_timestamps or not self .sync_recording_start
0 commit comments