@@ -159,28 +159,34 @@ async def _on_new_message(self) -> None:
159159 while True :
160160 try :
161161 client_id , message = await self ._message_queue .get ()
162- self .log .info (f"HANDLING NEW MESSAGE FROM '{ client_id } '" )
163- self .log .info (f"Message: { message } " )
164162 except asyncio .QueueShutDown :
165163 break
166164
167165 # Handle Awareness messages
168166 message_type = message [0 ]
169167 if message_type == YMessageType .AWARENESS :
168+ self .log .debug (f"Received AwarenessUpdate from '{ client_id } '." )
170169 self .handle_awareness_update (client_id , message )
170+ self .log .debug (f"Handled AwarenessUpdate from '{ client_id } '." )
171171 continue
172172
173173 # Handle Sync messages
174174 assert message_type == YMessageType .SYNC
175175 message_subtype = message [1 ] if len (message ) >= 2 else None
176176 if message_subtype == YSyncMessageSubtype .SYNC_STEP1 :
177+ self .log .info (f"Received SS1 from '{ client_id } '." )
177178 self .handle_sync_step1 (client_id , message )
179+ self .log .info (f"Handled SS1 from '{ client_id } '." )
178180 continue
179181 elif message_subtype == YSyncMessageSubtype .SYNC_STEP2 :
182+ self .log .info (f"Received SS2 from '{ client_id } '." )
180183 self .handle_sync_step2 (client_id , message )
184+ self .log .info (f"Handled SS2 from '{ client_id } '." )
181185 continue
182186 elif message_subtype == YSyncMessageSubtype .SYNC_UPDATE :
187+ self .log .info (f"Received SyncUpdate from '{ client_id } '." )
183188 self .handle_sync_update (client_id , message )
189+ self .log .info (f"Handled SyncUpdate from '{ client_id } '." )
184190 continue
185191 else :
186192 self .log .warning (
@@ -201,8 +207,6 @@ def handle_sync_step1(self, client_id: str, message: bytes) -> None:
201207 - Sending the reply to the client over WS, and
202208 - Sending a new SyncStep1 message immediately after.
203209 """
204- self .log .info (f"Handling SS1 message from client '{ client_id } '." )
205-
206210 # Mark client as desynced
207211 new_client = self .clients .get (client_id )
208212 self .clients .mark_desynced (client_id )
@@ -226,6 +230,7 @@ def handle_sync_step1(self, client_id: str, message: bytes) -> None:
226230 # TODO: remove the assert once websocket is made required
227231 assert isinstance (new_client .websocket , WebSocketHandler )
228232 new_client .websocket .write_message (sync_step2_message , binary = True )
233+ self .log .info (f"Sent SS2 reply to client '{ client_id } '." )
229234 except Exception as e :
230235 self .log .error (
231236 "An exception occurred when writing the SyncStep2 reply "
@@ -235,21 +240,19 @@ def handle_sync_step1(self, client_id: str, message: bytes) -> None:
235240 return
236241
237242 self .clients .mark_synced (client_id )
238- self .log .info (f"Sent SS2 reply to client '{ client_id } '." )
239243
240244 # Send SyncStep1 message
241245 try :
242246 assert isinstance (new_client .websocket , WebSocketHandler )
243247 sync_step1_message = pycrdt .create_sync_message (self ._ydoc )
244248 new_client .websocket .write_message (sync_step1_message , binary = True )
249+ self .log .info (f"Sent SS1 message to client '{ client_id } '." )
245250 except Exception as e :
246251 self .log .error (
247252 "An exception occurred when writing a SyncStep1 message "
248253 f"to newly-synced client '{ new_client .id } ':"
249254 )
250255 self .log .exception (e )
251- self .log .info (f"Sent SS1 message to client '{ client_id } '." )
252- self .log .info (f"Message: { sync_step1_message } " )
253256
254257
255258 def handle_sync_step2 (self , client_id : str , message : bytes ) -> None :
@@ -261,7 +264,6 @@ def handle_sync_step2(self, client_id: str, message: bytes) -> None:
261264 clients after this method is called via the `self.write_sync_update()`
262265 observer.
263266 """
264- self .log .info ("HANDLING SS2 MESSAGE" )
265267 try :
266268 message_payload = message [1 :]
267269 pycrdt .handle_sync_message (message_payload , self ._ydoc )
@@ -282,7 +284,6 @@ def handle_sync_update(self, client_id: str, message: bytes) -> None:
282284 clients after this method is called via the `self.write_sync_update()`
283285 observer.
284286 """
285- self .log .info ("HANDLING SYNCUPDATE" )
286287 # Remove client and kill websocket if received SyncUpdate when client is desynced
287288 if self ._should_ignore_update (client_id , "SyncUpdate" ):
288289 self .log .error (f"Should not receive SyncUpdate message when double handshake is not completed for client '{ client_id } ' and room '{ self .room_id } '" )
@@ -321,7 +322,6 @@ def write_sync_update(self, message_payload: bytes, client_id: str | None = None
321322
322323
323324 def handle_awareness_update (self , client_id : str , message : bytes ) -> None :
324- self .log .info ("HANDLING AWARENESS UPDATE" )
325325 # Apply the AwarenessUpdate message
326326 try :
327327 message_payload = pycrdt .read_message (message [1 :])
0 commit comments