Better error handling and debugging for call state issues (v2.1.2)

sip-notifier/config.yaml

@@ -1,5 +1,5 @@
 name: "SIP Voice Notifier"
-version: "2.1.1"
+version: "2.1.2"
 slug: "sip-notifier"
 description: "Send voice notifications via SIP phone calls"
 arch:

sip-notifier/sip_service.py

@@ -30,9 +30,7 @@ DEFAULT_SAMPLE_RATE = 8000
 def get_local_ip():
     """Get local IP address of the container."""
     try:
-        # Create a socket to determine the local IP
         s = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
-        # Connect to an external address (doesn't actually send data)
         s.connect(("8.8.8.8", 80))
         local_ip = s.getsockname()[0]
         s.close()
@@ -119,10 +117,15 @@ def place_sip_call(destination: str, audio_file: str, duration: int):
     
     _LOGGER.info(f"Local IP: {local_ip}")
     _LOGGER.info(f"SIP Server: {sip_server}")
-    _LOGGER.info(f"Calling: {destination}")
+    _LOGGER.info(f"SIP User: {sip_user}")
+    _LOGGER.info(f"Destination: {destination}")
+    
+    phone = None
+    call = None
     
     try:
         # Create VoIP phone
+        _LOGGER.info("Creating SIP phone...")
         phone = VoIPPhone(
             sip_server,
             5060,
@@ -135,31 +138,27 @@ def place_sip_call(destination: str, audio_file: str, duration: int):
             rtpPortHigh=20000
         )
         
+        _LOGGER.info("Starting SIP phone...")
         phone.start()
-        _LOGGER.info("SIP phone started, waiting for registration...")
-        time.sleep(3)  # Wait for registration
         
-        _LOGGER.info(f"Making call to: {destination}")
+        _LOGGER.info("Waiting for SIP registration...")
+        time.sleep(3)
         
-        # Make call
+        _LOGGER.info("Initiating call...")
         call = phone.call(destination)
         
+        _LOGGER.info(f"Call initiated, waiting for answer (state: {call.state})...")
+        
         # Wait for call to be answered
-        timeout = 15
+        timeout = 20
         elapsed = 0
-        while call.state != CallState.ANSWERED and elapsed < timeout:
+        while call.state not in [CallState.ANSWERED, CallState.ENDED] and elapsed < timeout:
             time.sleep(0.5)
             elapsed += 0.5
             if elapsed % 2 == 0:
-                _LOGGER.info(f"Waiting for answer... ({elapsed}s)")
+                _LOGGER.info(f"Call state: {call.state} ({elapsed}s)")
-        
-        if call.state != CallState.ANSWERED:
-            _LOGGER.warning(f"Call not answered within {timeout}s timeout")
-            _LOGGER.info(f"Final call state: {call.state}")
-            call.hangup()
-            phone.stop()
-            return
         
+        if call.state == CallState.ANSWERED:
             _LOGGER.info("✅ Call answered! Playing audio...")
             
             # Transmit audio file
@@ -172,16 +171,46 @@ def place_sip_call(destination: str, audio_file: str, duration: int):
             # Hangup
             _LOGGER.info("Hanging up...")
             call.hangup()
-        time.sleep(1)
-        
-        # Cleanup
-        phone.stop()
             _LOGGER.info("Call completed successfully")
             
+        elif call.state == CallState.ENDED:
+            _LOGGER.warning("Call ended before being answered (rejected or failed)")
+            raise Exception("Call was rejected or failed to connect")
+            
+        else:
+            _LOGGER.warning(f"Call not answered within {timeout}s")
+            _LOGGER.warning(f"Final state: {call.state}")
+            _LOGGER.warning("Possible issues:")
+            _LOGGER.warning("- SIP credentials may be incorrect")
+            _LOGGER.warning("- Destination number format may be wrong")
+            _LOGGER.warning("- SIP server may be rejecting the call")
+            _LOGGER.warning("- Network/firewall issues")
+            
+            # Try to end the call gracefully
+            try:
+                call.deny()
+            except:
+                pass
+            
+            raise Exception(f"Call timeout - state remained: {call.state}")
+        
+    except InvalidStateError as e:
+        _LOGGER.error(f"Invalid call state: {e}")
+        raise Exception(f"Call state error: {e}")
+        
     except Exception as e:
         _LOGGER.error(f"Call error: {e}", exc_info=True)
         raise
         
+    finally:
+        # Cleanup
+        if phone:
+            try:
+                _LOGGER.info("Stopping SIP phone...")
+                phone.stop()
+            except Exception as e:
+                _LOGGER.warning(f"Error stopping phone: {e}")
+
 
 @app.route('/health', methods=['GET'])
 def health():
@@ -238,14 +267,14 @@ def handle_send_notification():
 
 
 if __name__ == '__main__':
-    # Load config from Home Assistant add-on options
+    # Load config
     options_file = '/data/options.json'
     if os.path.exists(options_file):
         with open(options_file, 'r') as f:
             CONFIG = json.load(f)
             _LOGGER.info("Config loaded from options.json")
     else:
-        _LOGGER.warning("No options.json found, using environment variables")
+        _LOGGER.warning("No options.json found")
         CONFIG = {
             'sip_server': os.getenv('SIP_SERVER', ''),
             'sip_user': os.getenv('SIP_USER', ''),
@@ -256,13 +285,16 @@ if __name__ == '__main__':
     _LOGGER.info("=" * 60)
     _LOGGER.info("SIP Voice Notifier Add-on Ready")
     _LOGGER.info("=" * 60)
-    _LOGGER.info("Using pyVoIP from git (latest version)")
+    _LOGGER.info(f"SIP Server: {CONFIG.get('sip_server')}")
-    _LOGGER.info(f"SIP Server: {CONFIG.get('sip_server', 'not configured')}")
+    _LOGGER.info(f"SIP User: {CONFIG.get('sip_user')}")
-    _LOGGER.info(f"SIP User: {CONFIG.get('sip_user', 'not configured')}")
     _LOGGER.info(f"Local IP: {get_local_ip()}")
     _LOGGER.info("")
-    _LOGGER.info("To use this add-on, add configuration to configuration.yaml")
+    _LOGGER.info("⚠️  TROUBLESHOOTING:")
-    _LOGGER.info("See add-on README for details")
+    _LOGGER.info("If calls stay in DIALING state, check:")
+    _LOGGER.info("1. SIP credentials are correct")
+    _LOGGER.info("2. Phone number format (try with/without country code)")
+    _LOGGER.info("3. SIP account has calling permissions")
+    _LOGGER.info("4. Firewall allows UDP traffic on ports 5060, 10000-20000")
     _LOGGER.info("=" * 60)
     _LOGGER.info("Starting Flask service on port 8099")
     app.run(host='0.0.0.0', port=8099, debug=False)