DID Configuration

88 views
Skip to first unread message

davidbqzt

unread,
Mar 9, 2019, 11:37:04 PM3/9/19
to ASTPP
Hi

I'm trying to configure a DID for a customer, the DID is provided by a VoIP provider and I need to route it to their PBX, the flow is as follows:

PSTN-> DID -> VoIPProvider -> My ASTPP -> Client PBX

I can see that the call is arriving to my ASTPP but if I don't add the Provider IP the call is rejected, and if I add the IP address of the provider the route fails:

I've attached an image with the configuration of the DID.

This is the log when the IP Address is added:

2019-03-09 13:49:26.336796 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [1011edae-429c-11e9-bfd2-7d50e099b568]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9873 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7084 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1769260636 1 IN IP4 66.33.177.2
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 66.33.177.2
t=0 0
m=audio 23820 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALL...@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:26.336796 [DEBUG] switch_core_codec.c:111 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4767 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7507 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:90 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_channel.c:2249 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:143 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:26.336796 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:26.356775 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:26.356775 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:26.356775 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:26.356775 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:26.356775 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:26.356775 [INFO] mod_json_cdr.c:271 Process [1011edae-429c-11e9-bfd2-7d50e099b568.cdr.json]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_session.c:1665 Session 117934 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1683 Session 117934 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117934)
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:26.376770 [DEBUG] mod_sofia.c:343 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:27.716787 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [10e3a632-429c-11e9-bfd4-7d50e099b568]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9873 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7084 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 924625150 1 IN IP4 169.132.128.21
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.21
t=0 0
m=audio 22784 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALL...@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:27.716787 [DEBUG] switch_core_codec.c:111 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4767 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7507 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:90 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_channel.c:2249 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:143 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:27.716787 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:27.716787 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:27.716787 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:27.716787 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:27.716787 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:27.716787 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:27.716787 [INFO] mod_json_cdr.c:271 Process [10e3a632-429c-11e9-bfd4-7d50e099b568.cdr.json]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_session.c:1665 Session 117935 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1683 Session 117935 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117935)
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:27.736766 [DEBUG] mod_sofia.c:343 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:28.876786 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [1194b38c-429c-11e9-bfd6-7d50e099b568]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9873 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7084 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1969037261 1 IN IP4 169.132.128.20
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.20
t=0 0
m=audio 21898 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALL...@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:28.876786 [DEBUG] switch_core_codec.c:111 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4767 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7507 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:90 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_channel.c:2249 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:143 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:28.876786 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:28.876786 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:28.876786 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:28.876786 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:28.876786 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:28.876786 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:28.876786 [INFO] mod_json_cdr.c:271 Process [1194b38c-429c-11e9-bfd6-7d50e099b568.cdr.json]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_session.c:1665 Session 117936 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1683 Session 117936 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117936)
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:28.896792 [DEBUG] mod_sofia.c:343 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep

Why is this happening or how to correct it, Thank you?
20190309-ExampleDID-Configuration.png

Devang Nathwani

unread,
Mar 12, 2019, 2:10:47 PM3/12/19
to as...@googlegroups.com
Hello,

Do you have any customization in code?
Share 54 line number of astpp.dialplan.lua file please.
NOTE: use http://pastebin.freeswitch.org/ to share freeswitch logs.

--
=====================================================================
Documentation: https://astpp.readthedocs.io/
Please contact at sa...@inextrix.com for commercial support.
---
You received this message because you are subscribed to the Google Groups "ASTPP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to astpp+un...@googlegroups.com.
To post to this group, send email to as...@googlegroups.com.
Visit this group at https://groups.google.com/group/astpp.
To view this discussion on the web visit https://groups.google.com/d/msgid/astpp/c4723085-b21c-45ff-910a-4311f4158c99%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.


--
Thanks,
Devang Nathwani

Disclaimer:
The information contained in this communication is confidential and may be legally privileged. It is intended solely for the use of the individual or entity to whom it is addressed and others authorized to receive it. If you are not the intended recipient you are hereby notified that any disclosure, copying, distribution or taking action in reliance of the contents of this information is strictly prohibited and may be unlawful. Please notify the sender immediately and destroy all copies of this message and any attachments contained in it.

davidbqzt

unread,
Mar 12, 2019, 5:49:31 PM3/12/19
to ASTPP
Hi Devang,

No, I have no change to the code as it was installed.

This is the link to the file as requested: https://pastebin.freeswitch.org/view/7eee5725

Thanks for your help

David


On Saturday, March 9, 2019 at 11:37:04 PM UTC-5, davidbqzt wrote:
Hi

I'm trying to configure a DID for a customer, the DID is provided by a VoIP provider and I need to route it to their PBX, the flow is as follows:

PSTN-> DID -> VoIPProvider -> My ASTPP -> Client PBX

I can see that the call is arriving to my ASTPP but if I don't add the Provider IP the call is rejected, and if I add the IP address of the provider the route fails:

I've attached an image with the configuration of the DID.

This is the log when the IP Address is added:

2019-03-09 13:49:26.336796 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [1011edae-429c-11e9-bfd2-7d50e099b568]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9873 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7084 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1769260636 1 IN IP4 66.33.177.2
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 66.33.177.2
t=0 0
m=audio 23820 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:26.336796 [DEBUG] switch_core_codec.c:111 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4767 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7507 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:90 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_channel.c:2249 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:143 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:26.336796 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:26.356775 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:26.356775 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:26.356775 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:26.356775 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:26.356775 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:26.356775 [INFO] mod_json_cdr.c:271 Process [1011edae-429c-11e9-bfd2-7d50e099b568.cdr.json]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_session.c:1665 Session 117934 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1683 Session 117934 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117934)
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:26.376770 [DEBUG] mod_sofia.c:343 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:27.716787 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [10e3a632-429c-11e9-bfd4-7d50e099b568]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9873 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7084 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 924625150 1 IN IP4 169.132.128.21
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.21
t=0 0
m=audio 22784 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:27.716787 [DEBUG] switch_core_codec.c:111 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4767 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7507 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:90 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_channel.c:2249 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:143 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:27.716787 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:27.716787 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:27.716787 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:27.716787 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:27.716787 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:27.716787 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:27.716787 [INFO] mod_json_cdr.c:271 Process [10e3a632-429c-11e9-bfd4-7d50e099b568.cdr.json]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_session.c:1665 Session 117935 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1683 Session 117935 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117935)
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:27.736766 [DEBUG] mod_sofia.c:343 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:28.876786 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [1194b38c-429c-11e9-bfd6-7d50e099b568]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9873 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7084 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1969037261 1 IN IP4 169.132.128.20
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.20
t=0 0
m=audio 21898 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:28.876786 [DEBUG] switch_core_codec.c:111 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4767 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7507 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:90 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_channel.c:2249 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:143 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:28.876786 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:28.876786 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:28.876786 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:28.876786 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:28.876786 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:28.876786 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:28.876786 [INFO] mod_json_cdr.c:271 Process [1194b38c-429c-11e9-bfd6-7d50e099b568.cdr.json]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_session.c:1665 Session 117936 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1683 Session 117936 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117936)
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:28.896792 [DEBUG] mod_sofia.c:343 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep

Devang Nathwani

unread,
Mar 12, 2019, 11:17:22 PM3/12/19
to as...@googlegroups.com
Hello David,

Is your ASTPP v 3.6?
Because the content of file you shared and the content of same file of v3.6 is different, check here 

On Wed, 13 Mar 2019 at 3:19 AM, davidbqzt <davi...@gmail.com> wrote:
Hi Devang,

No, I have no change to the code as it was installed.

This is the link to the file as requested: https://pastebin.freeswitch.org/view/7eee5725

Thanks for your help

David


On Saturday, March 9, 2019 at 11:37:04 PM UTC-5, davidbqzt wrote:
Hi

I'm trying to configure a DID for a customer, the DID is provided by a VoIP provider and I need to route it to their PBX, the flow is as follows:

PSTN-> DID -> VoIPProvider -> My ASTPP -> Client PBX

I can see that the call is arriving to my ASTPP but if I don't add the Provider IP the call is rejected, and if I add the IP address of the provider the route fails:

I've attached an image with the configuration of the DID.

This is the log when the IP Address is added:

2019-03-09 13:49:26.336796 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [1011edae-429c-11e9-bfd2-7d50e099b568]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9873 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7084 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1769260636 1 IN IP4 66.33.177.2
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 66.33.177.2
t=0 0
m=audio 23820 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALL...@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:26.336796 [DEBUG] switch_core_codec.c:111 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4767 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7507 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:90 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_channel.c:2249 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:143 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:26.336796 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:26.356775 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:26.356775 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:26.356775 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:26.356775 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:26.356775 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:26.356775 [INFO] mod_json_cdr.c:271 Process [1011edae-429c-11e9-bfd2-7d50e099b568.cdr.json]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_session.c:1665 Session 117934 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1683 Session 117934 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117934)
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:26.376770 [DEBUG] mod_sofia.c:343 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:27.716787 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [10e3a632-429c-11e9-bfd4-7d50e099b568]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9873 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7084 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 924625150 1 IN IP4 169.132.128.21
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.21
t=0 0
m=audio 22784 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALL...@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:27.716787 [DEBUG] switch_core_codec.c:111 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4767 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7507 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:90 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_channel.c:2249 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:143 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:27.716787 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:27.716787 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:27.716787 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:27.716787 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:27.716787 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:27.716787 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:27.716787 [INFO] mod_json_cdr.c:271 Process [10e3a632-429c-11e9-bfd4-7d50e099b568.cdr.json]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_session.c:1665 Session 117935 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1683 Session 117935 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117935)
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:27.736766 [DEBUG] mod_sofia.c:343 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:28.876786 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [1194b38c-429c-11e9-bfd6-7d50e099b568]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9873 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7084 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1969037261 1 IN IP4 169.132.128.20
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.20
t=0 0
m=audio 21898 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALL...@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:28.876786 [DEBUG] switch_core_codec.c:111 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4767 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7507 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:90 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_channel.c:2249 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:143 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:28.876786 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:28.876786 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:28.876786 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:28.876786 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:28.876786 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:28.876786 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:28.876786 [INFO] mod_json_cdr.c:271 Process [1194b38c-429c-11e9-bfd6-7d50e099b568.cdr.json]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_session.c:1665 Session 117936 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1683 Session 117936 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALL...@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117936)
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:28.896792 [DEBUG] mod_sofia.c:343 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALL...@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALL...@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep

Why is this happening or how to correct it, Thank you?

--
=====================================================================
Documentation: https://astpp.readthedocs.io/
Please contact at sa...@inextrix.com for commercial support.
---
You received this message because you are subscribed to the Google Groups "ASTPP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to astpp+un...@googlegroups.com.
To post to this group, send email to as...@googlegroups.com.
Visit this group at https://groups.google.com/group/astpp.

For more options, visit https://groups.google.com/d/optout.

davidbqzt

unread,
Mar 14, 2019, 12:20:33 PM3/14/19
to ASTPP
Hi Devang,

Yes, it's supposed it is a 3.6, as it shows on the footer of the page.

Anyway, I will copy the content of the file on the link you're sending, test and let you know.

Thanks.

David.

On Tuesday, March 12, 2019 at 10:17:22 PM UTC-5, Devang Nathwani wrote:
Hello David,

Is your ASTPP v 3.6?
Because the content of file you shared and the content of same file of v3.6 is different, check here 
On Wed, 13 Mar 2019 at 3:19 AM, davidbqzt <davi...@gmail.com> wrote:
Hi Devang,

No, I have no change to the code as it was installed.

This is the link to the file as requested: https://pastebin.freeswitch.org/view/7eee5725

Thanks for your help

David


On Saturday, March 9, 2019 at 11:37:04 PM UTC-5, davidbqzt wrote:
Hi

I'm trying to configure a DID for a customer, the DID is provided by a VoIP provider and I need to route it to their PBX, the flow is as follows:

PSTN-> DID -> VoIPProvider -> My ASTPP -> Client PBX

I can see that the call is arriving to my ASTPP but if I don't add the Provider IP the call is rejected, and if I add the IP address of the provider the route fails:

I've attached an image with the configuration of the DID.

This is the log when the IP Address is added:

2019-03-09 13:49:26.336796 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [1011edae-429c-11e9-bfd2-7d50e099b568]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9873 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7084 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1769260636 1 IN IP4 66.33.177.2
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 66.33.177.2
t=0 0
m=audio 23820 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:26.336796 [DEBUG] switch_core_codec.c:111 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:26.336796 [DEBUG] switch_core_media.c:4767 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:26.336796 [DEBUG] sofia.c:7507 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:90 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.336796 [DEBUG] switch_channel.c:2249 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:26.336796 [DEBUG] mod_sofia.c:143 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:26.336796 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:26.336796 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:26.356775 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:26.356775 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:26.356775 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:26.356775 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:26.356775 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:26.356775 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:26.356775 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117934)
2019-03-09 13:49:26.356775 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:26.356775 [INFO] mod_json_cdr.c:271 Process [1011edae-429c-11e9-bfd2-7d50e099b568.cdr.json]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_session.c:1665 Session 117934 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1683 Session 117934 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:26.376770 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117934)
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:26.376770 [DEBUG] mod_sofia.c:343 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:26.376770 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:27.716787 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [10e3a632-429c-11e9-bfd4-7d50e099b568]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9873 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7084 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 924625150 1 IN IP4 169.132.128.21
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.21
t=0 0
m=audio 22784 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:27.716787 [DEBUG] switch_core_codec.c:111 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:27.716787 [DEBUG] switch_core_media.c:4767 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:27.716787 [DEBUG] sofia.c:7507 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:90 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_channel.c:2249 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:143 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:27.716787 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:27.716787 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:27.716787 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:27.716787 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:27.716787 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:27.716787 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:27.716787 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:27.716787 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117935)
2019-03-09 13:49:27.716787 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:27.716787 [INFO] mod_json_cdr.c:271 Process [10e3a632-429c-11e9-bfd4-7d50e099b568.cdr.json]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_session.c:1665 Session 117935 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1683 Session 117935 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:27.736766 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117935)
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:27.736766 [DEBUG] mod_sofia.c:343 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:27.736766 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep
2019-03-09 13:49:28.876786 [NOTICE] switch_channel.c:1104 New Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [1194b38c-429c-11e9-bfd6-7d50e099b568]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_NEW (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9873 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 receiving invite from Provider.IP.ADD.RSS:5060 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:9989 IP Provider.IP.ADD.RSS Approved by acl "default[]". Access Granted.
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7084 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 entering state [received][100]
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=SBCSIPUAS 1969037261 1 IN IP4 169.132.128.20
s=SBCSIPUAS SIP STACK v1.0
c=IN IP4 169.132.128.20
t=0 0
m=audio 21898 RTP/AVP 0 18 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-03-09 13:49:28.876786 [DEBUG] switch_core_codec.c:111 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Original read codec set to PCMU:0
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-03-09 13:49:28.876786 [DEBUG] switch_core_media.c:4767 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-03-09 13:49:28.876786 [DEBUG] sofia.c:7507 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_NEW -> CS_INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:603 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State NEW
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_INIT (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:90 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:40 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard INIT
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:48 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_INIT -> CS_ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:627 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State INIT going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_ROUTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_channel.c:2249 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change DOWN -> RINGING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:143 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA ROUTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:236 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard ROUTING
2019-03-09 13:49:28.876786 [INFO] mod_dialplan_xml.c:637 Processing CALLERID <+CALLERID>->17738773002 in context default
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x168e860 Connected.
2019-03-09 13:49:28.876786 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
2019-03-09 13:49:28.876786 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 17738773002
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:203 /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: attempt to concatenate global 'callerid_number' (a nil value)
stack traceback:
        /usr/local/freeswitch/scripts/astpp/scripts/astpp.dialplan.lua:54: in main chunk
        [C]: in function 'dofile'
        /usr/local/freeswitch/scripts/astpp/astpp.lua:79: in main chunk
2019-03-09 13:49:28.876786 [ERR] mod_lua.cpp:271 LUA script parse/execute error!
2019-03-09 13:49:28.876786 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x168e860 released.
2019-03-09 13:49:28.876786 [WARNING] mod_dialplan_xml.c:667 Context default not found
2019-03-09 13:49:28.876786 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2019-03-09 13:49:28.876786 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_ROUTING] [NO_ROUTE_DESTINATION]
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:643 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State ROUTING going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_HANGUP (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:850 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Callstate Change RINGING -> HANGUP
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:438 Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 hanging up, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:60 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard HANGUP, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:852 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State HANGUP going to sleep
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:619 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_HANGUP -> CS_REPORTING
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:584 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_REPORTING (Cur 1 Tot 117936)
2019-03-09 13:49:28.876786 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING
2019-03-09 13:49:28.876786 [INFO] mod_json_cdr.c:271 Process [1194b38c-429c-11e9-bfd6-7d50e099b568.cdr.json]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:174 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard REPORTING, cause: NO_ROUTE_DESTINATION
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:938 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State REPORTING going to sleep
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:610 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State Change CS_REPORTING -> CS_DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_session.c:1665 Session 117936 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Locked, Waiting on external entities
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1683 Session 117936 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Ended
2019-03-09 13:49:28.896792 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 [CS_DESTROY]
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:741 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) Running State Change CS_DESTROY (Cur 0 Tot 117936)
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY
2019-03-09 13:49:28.896792 [DEBUG] mod_sofia.c:343 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 SOFIA DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:181 sofia/default/CALLERID@Provider.IP.ADD.RSS:5060 Standard DESTROY
2019-03-09 13:49:28.896792 [DEBUG] switch_core_state_machine.c:751 (sofia/default/CALLERID@Provider.IP.ADD.RSS:5060) State DESTROY going to sleep

Why is this happening or how to correct it, Thank you?

--
=====================================================================
Documentation: https://astpp.readthedocs.io/
Please contact at sa...@inextrix.com for commercial support.
---
You received this message because you are subscribed to the Google Groups "ASTPP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to astpp+un...@googlegroups.com.
To post to this group, send email to as...@googlegroups.com.
Visit this group at https://groups.google.com/group/astpp.
To view this discussion on the web visit https://groups.google.com/d/msgid/astpp/5c105270-3c60-4df2-a00a-b1f165b5278b%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

davidbqzt

unread,
Mar 14, 2019, 12:33:35 PM3/14/19
to ASTPP
Hi Devang,

Yes! it works!

I have no idea why my file was different but using the current file works.

Thanks,

David.
Reply all
Reply to author
Forward
0 new messages