Fix PySIP-to-PySIP calls on same device and recording issues

- Fix RTP port collision: randomize starting port and check availability
- Fix message handler pass-through in _send_invite() for incoming calls
- Fix recording to run in background while greeting plays simultaneously
- Fix silence timeout to only trigger after receiving actual packets
- Add proper callback chaining so DTMF detection works during recording
- Add debug logging for recording troubleshooting

Author: moha-abdi

PySIP/call.py

@@ -719,25 +719,39 @@ async def _send_invite(self, timeout: float) -> SIPResponse | None:
         # Create response future
         response_future: asyncio.Future = asyncio.get_running_loop().create_future()
 
+        old_handler = self._transport.get_data_handler()
+        
         def on_response(data: bytes, addr: Address) -> None:
             try:
                 parser = SIPParser()
                 msg = parser.parse(data)
-                if hasattr(msg, 'status_code') and msg.call_id == self._call_id:
-                    if msg.status_code == 100:
-                        pass  # Ignore TRYING
-                    elif msg.status_code == 180 or msg.status_code == 183:
-                        self._state = CallState.RINGING
-                        self._emit_event("ringing")
-                        # Handle early media on 183
-                        if msg.status_code == 183 and self._early_media and msg.body:
-                            self._remote_sdp = msg.body
-                    elif not response_future.done():
-                        response_future.set_result(msg)
+                if hasattr(msg, 'status_code'):
+                    # It's a response
+                    if msg.call_id == self._call_id:
+                        # Our response
+                        if msg.status_code == 100:
+                            pass  # Ignore TRYING
+                        elif msg.status_code == 180 or msg.status_code == 183:
+                            self._state = CallState.RINGING
+                            self._emit_event("ringing")
+                            # Handle early media on 183
+                            if msg.status_code == 183 and self._early_media and msg.body:
+                                self._remote_sdp = msg.body
+                        elif not response_future.done():
+                            response_future.set_result(msg)
+                    else:
+                        # Not our response, pass to old handler
+                        if old_handler:
+                            old_handler(data, addr)
+                else:
+                    # It's a request (e.g., incoming INVITE), pass to old handler
+                    if old_handler:
+                        old_handler(data, addr)
             except Exception as e:
                 logger.error(f"Error parsing response: {e}")
-        
-        old_handler = self._transport.get_data_handler()
+                # On error, try passing to old handler
+                if old_handler:
+                    old_handler(data, addr)
         self._transport.set_data_handler(on_response)
 
         try:

PySIP/features/recording/recorder.py

@@ -139,6 +139,7 @@ async def record(
         audio_chunks: list[bytes] = []
         start_time = time.time()
         last_voice_time = start_time
+        packets_received = 0  # Track packet count for debugging
 
         # Calculate limits
         max_bytes = int(self._max_size_mb * 1024 * 1024)
@@ -155,11 +156,13 @@ async def record(
             call_codec = PCMUCodec()
 
         def on_rtp_packet(data: bytes, addr) -> None:
-            nonlocal bytes_recorded, last_voice_time
+            nonlocal bytes_recorded, last_voice_time, packets_received
 
             if stop_event.is_set():
                 return
 
+            packets_received += 1
+            
             # Extract payload (skip RTP header)
             payload = data[12:] if len(data) > 12 else data
 
@@ -184,43 +187,68 @@ def on_rtp_packet(data: bytes, addr) -> None:
                 if bytes_recorded >= max_bytes:
                     logger.warning("Recording size limit reached")
                     stop_event.set()
+                
+                # Log progress periodically
+                if packets_received == 1:
+                    logger.debug(f"First RTP packet received from {addr}")
+                elif packets_received % 500 == 0:
+                    logger.debug(f"Recording: {packets_received} packets, {bytes_recorded} bytes")
 
             except Exception as e:
                 logger.debug(f"Recording decode error: {e}")
 
-        # Hook into RTP session
+        # Hook into RTP session - chain callbacks so both recording and
+        # the call's own handler (DTMF, etc.) work simultaneously
         old_callback = None
         if call._rtp_session:
             old_callback = call._rtp_session._on_packet
-            call._rtp_session.on_packet(on_rtp_packet)
+            
+            def chained_callback(data: bytes, addr) -> None:
+                # First, call the recording handler
+                on_rtp_packet(data, addr)
+                # Then, call the original handler (for DTMF, etc.)
+                if old_callback:
+                    old_callback(data, addr)
+            
+            call._rtp_session.on_packet(chained_callback)
+            logger.debug(f"Recording started, RTP callback chained (had old: {old_callback is not None})")
+        else:
+            logger.warning("No RTP session available for recording!")
 
         try:
             # Record until conditions met
             while not stop_event.is_set():
                 # Check duration
                 elapsed = time.time() - start_time
                 if elapsed >= max_duration:
-                    logger.debug("Recording max duration reached")
+                    logger.debug(f"Recording max duration reached ({elapsed:.1f}s, {packets_received} packets)")
                     break
 
-                # Check silence timeout
-                if silence_timeout:
+                # Check silence timeout - but only if we've received at least some packets
+                # This prevents timeout before audio stream even starts
+                if silence_timeout and packets_received > 0:
                     silence_duration = time.time() - last_voice_time
                     if silence_duration >= silence_timeout:
-                        logger.debug("Recording silence timeout")
+                        logger.debug(f"Recording silence timeout ({silence_duration:.1f}s silence, {packets_received} packets)")
                         break
 
                 # Check call state
                 if not call.is_active:
-                    logger.debug("Call ended during recording")
+                    logger.debug(f"Call ended during recording ({packets_received} packets received)")
                     break
 
                 await asyncio.sleep(0.1)
 
         finally:
-            # Restore callback
-            if call._rtp_session and old_callback:
-                call._rtp_session.on_packet(old_callback)
+            # Restore original callback
+            if call._rtp_session:
+                if old_callback:
+                    call._rtp_session.on_packet(old_callback)
+                    logger.debug("Recording stopped, original RTP callback restored")
+                else:
+                    # No old callback - just clear
+                    call._rtp_session._on_packet = None
+                    logger.debug("Recording stopped, RTP callback cleared")
 
         # Combine audio
         if audio_chunks:
@@ -230,6 +258,8 @@ def on_rtp_packet(data: bytes, addr) -> None:
 
         duration_ms = int((time.time() - start_time) * 1000)
 
+        logger.info(f"Recording complete: {packets_received} packets, {len(audio)} bytes, {duration_ms}ms")
+        
         return Recording(
             audio=audio,
             duration_ms=duration_ms,

PySIP/session/manager.py

@@ -76,6 +76,8 @@ def __init__(
         local_port: int = 5060,
         rtp_port_range: tuple[int, int] = (10000, 20000),
     ):
+        import random
+        
         self._transport = transport
         self._config = config or CallManagerConfig()
         self._calls: dict[str, "Call"] = {}  # call_id -> Call
@@ -86,7 +88,11 @@ def __init__(
         self._local_ip = local_ip
         self._local_port = local_port
         self._rtp_port_range = rtp_port_range
-        self._next_rtp_port = rtp_port_range[0]
+        # Randomize starting port to avoid collisions when multiple clients
+        # start on the same machine
+        range_size = (rtp_port_range[1] - rtp_port_range[0]) // 2
+        random_offset = random.randint(0, range_size - 1) * 2  # Even ports only
+        self._next_rtp_port = rtp_port_range[0] + random_offset
 
     @property
     def active_calls(self) -> int:
@@ -152,14 +158,41 @@ async def stop(self) -> None:
         logger.info("CallManager stopped")
 
     def _allocate_rtp_port(self) -> int:
-        """Allocate next RTP port."""
-        port = self._next_rtp_port
-        self._next_rtp_port += 2  # RTP uses even ports
+        """
+        Allocate next available RTP port.
         
-        if self._next_rtp_port >= self._rtp_port_range[1]:
-            self._next_rtp_port = self._rtp_port_range[0]
+        Tests port availability before returning to avoid
+        'address already in use' errors when multiple clients
+        run on the same machine.
+        """
+        import socket
+        import random
 
-        return port
+        # Get the range size and try all ports if needed
+        range_start, range_end = self._rtp_port_range
+        range_size = (range_end - range_start) // 2  # Divided by 2 since RTP uses even ports
+        
+        for _ in range(range_size):
+            port = self._next_rtp_port
+            self._next_rtp_port += 2  # RTP uses even ports
+            
+            if self._next_rtp_port >= range_end:
+                self._next_rtp_port = range_start
+            
+            # Test if port is available
+            try:
+                sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
+                sock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
+                sock.bind(("0.0.0.0", port))
+                sock.close()
+                return port
+            except OSError:
+                # Port in use, try next one
+                continue
+        
+        # Fallback: return a random port in range and hope for the best
+        # This shouldn't happen in normal operation
+        return random.randrange(range_start, range_end, 2)
 
     async def create_call(
         self,

examples/record_call.py

@@ -23,12 +23,21 @@
 
 import argparse
 import asyncio
+import logging
 import os
 import sys
 
 # Add parent directory to path for development
 sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
 
+# Enable debug logging for recording
+logging.basicConfig(
+    level=logging.INFO,
+    format='%(asctime)s - %(name)s - %(levelname)s - %(message)s'
+)
+# Set recording module to DEBUG for detailed info
+logging.getLogger('PySIP.features.recording').setLevel(logging.DEBUG)
+
 from dotenv import load_dotenv
 from PySIP import SIPClient
 from PySIP.exceptions import (
@@ -181,25 +190,30 @@ async def handle_inbound_call(call, args):
         await call.answer()
         print("Call answered!")
 
-        # Welcome message
+        # Small delay to ensure RTP session is fully ready
+        await asyncio.sleep(0.2)
+        
+        # Start recording in background task so we can play greeting simultaneously
+        print("\nRecording started...")
+        print(f"(Recording for up to {args.max_duration}s, or {args.silence_timeout}s of silence)")
+        
+        recording_task = asyncio.create_task(
+            call.record(
+                max_duration=args.max_duration,
+                silence_timeout=args.silence_timeout,
+            )
+        )
+        
+        # Play welcome message WHILE recording (caller's audio is being captured)
         await call.say(
             "Hello! This call is being recorded. "
-            "Please say something after the beep. "
+            "Please say something. "
             f"Recording will stop after {int(args.silence_timeout)} seconds of silence "
             f"or {int(args.max_duration)} seconds total."
         )
 
-        # Play a beep sound
-        await call.say("Beep!")
-        
-        # Start recording
-        print("\nRecording started...")
-        print(f"(Recording for up to {args.max_duration}s, or {args.silence_timeout}s of silence)")
-        
-        recording = await call.record(
-            max_duration=args.max_duration,
-            silence_timeout=args.silence_timeout,
-        )
+        # Wait for recording to complete
+        recording = await recording_task
 
         print(f"\nRecording finished!")
         print(f"  Duration: {recording.duration_seconds:.1f} seconds")
@@ -210,7 +224,7 @@ async def handle_inbound_call(call, args):
         recording.save(filename)
         print(f"  Saved to: {filename}")
 
-        # Thank you message
+        # Thank you message (after recording is done)
         await call.say(
             "Thank you for your recording. "
             "The audio has been saved. Goodbye!"
@@ -222,6 +236,8 @@ async def handle_inbound_call(call, args):
 
     except Exception as e:
         print(f"Error handling call: {e}")
+        import traceback
+        traceback.print_exc()
         try:
             await call.hangup()
         except Exception: