Estimados, buenas tardes. Soy nuevo en el grupo, pero no en voip ni asterisk, pero estoy con un problema que no puedo llegar a solucionarlo y llevo unos dias ya cansado mentalmente.
Tengo un Asterisk 18.13.0, corriendo sobre centos 7.9 con mysql (realtime), todo funcionando bien, menos las entrantes desde un proveedor de telefonia ip.
El asterisk esta virtualizado en un vmware, y detras de un router/firewall, sin SIP ALG, y los puertos correctamente abiertos, el NATEO correcto y no creo que el problema venga por ahi ya que las salientes funcionan y el registro contra este proveeedor es correcto.
Creo que el problema lo tengo con el realtime ya que la llamada entrante me la busca como una extension y no deberia.
Les dejo el LOG de una llamada entrante al did para que se hagan el escenario en la cabeza:
[2022-09-02 13:33:31.102] DEBUG[1799] res_pjsip_registrar.c: Woke up at 1662136411 Interval: 30
[2022-09-02 13:33:31.102] DEBUG[1799] res_pjsip_registrar.c: Expiring 0 contacts
[2022-09-02 13:33:33.806] DEBUG[1807] acl.c: For destination '190.2.20.2', our source address is '192.168.31.15'.
[2022-09-02 13:33:33.806] DEBUG[1807] chan_sip.c: Target address
190.2.20.2:5060 is not local, substituting externaddr
[2022-09-02 13:33:33.806] DEBUG[1807] chan_sip.c: Setting AST_TRANSPORT_UDP with address
191.97.160.204:5060[2022-09-02 13:33:33.806] DEBUG[1807] netsock2.c: Splitting '
190.2.20.2:5060' into...
[2022-09-02 13:33:33.806] DEBUG[1807] netsock2.c: ...host '190.2.20.2' and port '5060'.
[2022-09-02 13:33:33.806] DEBUG[1807] chan_sip.c: Allocating new SIP dialog for SDb6uld01-1f9da428431be83e2fcf1a3b91799d4b-c540d43 - INVITE (No RTP)
[2022-09-02 13:33:33.806] DEBUG[1807][C-00000016] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[2022-09-02 13:33:33.806] DEBUG[1807][C-00000016] netsock2.c: Splitting '
190.2.20.2:5060' into...
[2022-09-02 13:33:33.806] DEBUG[1807][C-00000016] netsock2.c: ...host '190.2.20.2' and port '5060'.
[2022-09-02 13:33:33.806] DEBUG[1807][C-00000016] netsock2.c: Splitting '190.2.20.2' into...
[2022-09-02 13:33:33.806] DEBUG[1807][C-00000016] netsock2.c: ...host '190.2.20.2' and port ''.
[2022-09-02 13:33:33.807] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.807] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE name = '1166232791' AND host = 'dynamic'
[2022-09-02 13:33:33.809] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.809] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE name = '1166232791'
[2022-09-02 13:33:33.810] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.810] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE host = '190.2.20.2' AND callbackextension = '1139848042' AND port = '5060'
[2022-09-02 13:33:33.812] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.812] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE host = '190.2.20.2' AND port = '5060'
[2022-09-02 13:33:33.813] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.813] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE ipaddr = '190.2.20.2' AND port = '5060'
[2022-09-02 13:33:33.814] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.814] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE host = '190.2.20.2' AND insecure LIKE '%port%' ESCAPE '\\' ORDER BY host
[2022-09-02 13:33:33.815] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Connection okay.
[2022-09-02 13:33:33.816] DEBUG[1807][C-00000016] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE ipaddr = '190.2.20.2' AND insecure LIKE '%port%' ESCAPE '\\' ORDER BY ipaddr
[2022-09-02 13:33:33.816] DEBUG[1807][C-00000016] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fed480043e0'
[2022-09-02 13:33:33.817] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) RTP allocated port 11078
[2022-09-02 13:33:33.817] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) ICE creating session
0.0.0.0:11078 (11078)
[2022-09-02 13:33:33.817] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) ICE create
[2022-09-02 13:33:33.820] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) ICE add system candidates
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] netsock2.c: Splitting '192.168.31.15' into...
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] netsock2.c: ...host '192.168.31.15' and port ''.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) ICE add candidate:
192.168.31.15:11078, 2130706431
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: RTP instance '0x7fed480043e0' is setup and ready to go
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) ICE stopped
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] netsock2.c: Splitting 'ip31store' into...
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] netsock2.c: ...host 'ip31store' and port ''.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) RTCP setup on RTP instance
[2022-09-02 13:33:33.821] VERBOSE[1807][C-00000016] netsock2.c: Using SIP RTP TOS bits 184
[2022-09-02 13:33:33.821] VERBOSE[1807][C-00000016] netsock2.c: Using SIP RTP CoS mark 5
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Setting NAT on RTP to On
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing session-level SDP o=BroadWorks 10141784 1 IN IP4 190.2.20.2... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED OR FAILED.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] netsock2.c: Splitting '190.2.20.2' into...
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] netsock2.c: ...host '190.2.20.2' and port ''.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing session-level SDP c=IN IP4 190.2.20.2... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7fed18566250
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fed18566250
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7fed18566250
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=3gOoBTC... UNSUPPORTED OR FAILED.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK.
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7fed48004168) from 0x7fed18566250 to 0x7fed18566250
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x7fed480054c8) from 0x7fed18566250 to 0x7fed18566250
[2022-09-02 13:33:33.821] DEBUG[1807][C-00000016] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x7fed4800e328) from 0x7fed18566250 to 0x7fed18566250
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Crossover copying tx to rx payload mapping 101 (0x7fed480075d8) from 0x7fed18566250 to 0x7fed18566250
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] acl.c: For destination '190.2.20.2', our source address is '192.168.31.15'.
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) RTCP setting address on RTP instance
[2022-09-02 13:33:33.822] VERBOSE[1807][C-00000016] res_rtp_asterisk.c: 0x7fed48014a90 -- Strict RTP learning after remote address set to:
190.2.20.2:42212[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying rx payload mapping 0 (0x7fed48004168) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying rx payload mapping 8 (0x7fed480054c8) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying rx payload mapping 18 (0x7fed4800e328) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying rx payload mapping 101 (0x7fed480075d8) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying tx payload mapping 0 (0x7fed48004168) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying tx payload mapping 8 (0x7fed480054c8) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying tx payload mapping 18 (0x7fed4800e328) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] rtp_engine.c: Copying tx payload mapping 101 (0x7fed480075d8) from 0x7fed18566250 to 0x7fed480045b8
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] res_rtp_asterisk.c: (0x7fed480043e0) RTCP ignoring duplicate property
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] chan_sip.c: We're settling with these formats: (alaw|ulaw)
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] chan_sip.c: Checking SIP call limits for device
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] chan_sip.c: Updating call counter for incoming call
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] netsock2.c: Splitting '
191.97.160.204:5060' into...
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] netsock2.c: ...host '191.97.160.204' and port ''.
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] netsock2.c: Splitting '190.2.20.2' into...
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] netsock2.c: ...host '190.2.20.2' and port ''.
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] chan_sip.c: Got SIP INVITE to non-local domain '191.97.160.204'; refusing request.
[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for
190.2.20.2:5060[2022-09-02 13:33:33.822] DEBUG[1807][C-00000016] chan_sip.c: Updating call counter for incoming call
[2022-09-02 13:33:33.824] DEBUG[1771] devicestate.c: No provider found, checking channel drivers for SIP - EXT-INIPlan
[2022-09-02 13:33:33.824] DEBUG[1771] chan_sip.c: Checking device state for peer EXT-INIPlan
[2022-09-02 13:33:33.824] DEBUG[1771] devicestate.c: Changing state for SIP/EXT-INIPlan - state 1 (Not in use)
[2022-09-02 13:33:33.824] DEBUG[1771] devicestate.c: No provider found, checking channel drivers for SIP - EXT-INIPlan
[2022-09-02 13:33:33.824] DEBUG[1771] chan_sip.c: Checking device state for peer EXT-INIPlan
[2022-09-02 13:33:33.824] DEBUG[1771] devicestate.c: Changing state for SIP/EXT-INIPlan - state 1 (Not in use)
[2022-09-02 13:33:33.839] DEBUG[1807][C-00000016] chan_sip.c: **** Received ACK (6) - Command in SIP ACK
[2022-09-02 13:33:33.839] DEBUG[1807][C-00000016] chan_sip.c: Stopping retransmission on 'SDb6uld01-1f9da428431be83e2fcf1a3b91799d4b-c540d43' of Response 1066390485: Match Found
[2022-09-02 13:33:33.839] DEBUG[1807] chan_sip.c: Destroying SIP dialog SDb6uld01-1f9da428431be83e2fcf1a3b91799d4b-c540d43
[2022-09-02 13:33:33.839] DEBUG[1807] res_rtp_asterisk.c: (0x7fed480043e0) DTLS stop
[2022-09-02 13:33:33.839] DEBUG[1807] res_rtp_asterisk.c: (0x7fed480043e0) DTLS srtp - stopped timeout timer'
[2022-09-02 13:33:33.839] DEBUG[1807] res_rtp_asterisk.c: (0x7fed480043e0) DTLS srtp - stopped timeout timer'
[2022-09-02 13:33:33.839] DEBUG[1807] res_rtp_asterisk.c: (0x7fed480043e0) ICE RTP transport deallocating
[2022-09-02 13:33:33.839] DEBUG[1807] rtp_engine.c: Destroyed RTP instance '0x7fed480043e0'
la llamada entra, pero mi asterisk devuelve un 403 al proveedor, y estoy seguro que eso lo genera el check que hace contra el mysql. O no?
Tengo otro asterisk sin realtime, configurado de la misma forma y funciona sin problemas con el mismo proveedor.