SOLVED Call issues

Status
Not open for further replies.
N

nufay

New Member
May 8, 2019
15
1
3
Ukraine
I'm new to FreeSwitch and FusionPBX accordingly.

I set up a few Digium phones and call between them works great.
Then i added a softphone, but when i tried to call to Digium phone, call is being hung up.
I checked log files for something useful, but i didn't find anything useful about why call is not being made

Code: 
2019-06-11 16:01:00.648753 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/304@192.168.0.6:5060 [f6251d8e-8c48-11e9-9e22-9ff7af3d5200]
2019-06-11 16:01:00.648753 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_NEW (Cur 1 Tot 34)
2019-06-11 16:01:00.648753 [DEBUG] sofia.c:9873 sofia/internal/304@192.168.0.6:5060 receiving invite from 192.168.1.218:41219 version: 1.6.20  64bit
2019-06-11 16:01:00.648753 [DEBUG] sofia.c:9989 IP 192.168.1.218 Approved by acl "domains[]". Access Granted.
2019-06-11 16:01:00.668719 [DEBUG] sofia.c:7084 Channel sofia/internal/304@192.168.0.6:5060 entering state [received][100]
2019-06-11 16:01:00.668719 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 137118444036 1 IN IP4 192.168.1.218
s=Cpc session
c=IN IP4 192.168.1.218
t=0 0
m=audio 49994 RTP/AVP 9 8 0 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/304@192.168.0.6:5060 G722/8000 20 ms 160 samples 64000 bits 1 channels
2019-06-11 16:01:00.668719 [DEBUG] switch_core_codec.c:111 sofia/internal/304@192.168.0.6:5060 Original read codec set to G722:9
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2019-06-11 16:01:00.668719 [DEBUG] switch_core_media.c:4767 sofia/internal/304@192.168.0.6:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2019-06-11 16:01:00.668719 [DEBUG] sofia.c:7507 (sofia/internal/304@192.168.0.6:5060) State Change CS_NEW -> CS_INIT
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/304@192.168.0.6:5060) State NEW
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_INIT (Cur 1 Tot 34)
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/304@192.168.0.6:5060) State INIT
2019-06-11 16:01:00.668719 [DEBUG] mod_sofia.c:90 sofia/internal/304@192.168.0.6:5060 SOFIA INIT
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:40 sofia/internal/304@192.168.0.6:5060 Standard INIT
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/304@192.168.0.6:5060) State Change CS_INIT -> CS_ROUTING
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/304@192.168.0.6:5060) State INIT going to sleep
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_ROUTING (Cur 1 Tot 34)
2019-06-11 16:01:00.668719 [DEBUG] switch_channel.c:2249 (sofia/internal/304@192.168.0.6:5060) Callstate Change DOWN -> RINGING
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/304@192.168.0.6:5060) State ROUTING
2019-06-11 16:01:00.668719 [DEBUG] mod_sofia.c:143 sofia/internal/304@192.168.0.6:5060 SOFIA ROUTING
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:236 sofia/internal/304@192.168.0.6:5060 Standard ROUTING
2019-06-11 16:01:00.668719 [INFO] mod_dialplan_xml.c:637 Processing fusion <304>->204 in context public
Dialplan: sofia/internal/304@192.168.0.6:5060 parsing [public->caller-details] continue=true
Dialplan: sofia/internal/304@192.168.0.6:5060 Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/internal/304@192.168.0.6:5060 Action export(call_direction=inbound) INLINE
EXECUTE sofia/internal/304@192.168.0.6:5060 export(call_direction=inbound)
2019-06-11 16:01:00.668719 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/304@192.168.0.6:5060 Action set(caller_destination=${destination_number}) INLINE
EXECUTE sofia/internal/304@192.168.0.6:5060 set(caller_destination=204)
2019-06-11 16:01:00.668719 [DEBUG] mod_dptools.c:1548 SET sofia/internal/304@192.168.0.6:5060 [caller_destination]=[204]
Dialplan: sofia/internal/304@192.168.0.6:5060 Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE sofia/internal/304@192.168.0.6:5060 set(caller_id_name=fusion)
2019-06-11 16:01:00.668719 [DEBUG] mod_dptools.c:1548 SET sofia/internal/304@192.168.0.6:5060 [caller_id_name]=[fusion]
Dialplan: sofia/internal/304@192.168.0.6:5060 Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/304@192.168.0.6:5060 parsing [public->200] continue=false
Dialplan: sofia/internal/304@192.168.0.6:5060 Regex (FAIL) [200] destination_number(204) =~ /^(200)$/ break=on-false
Dialplan: sofia/internal/304@192.168.0.6:5060 parsing [public->not-found] continue=false
Dialplan: sofia/internal/304@192.168.0.6:5060 Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/internal/304@192.168.0.6:5060 Action export(call_direction=inbound) INLINE
EXECUTE sofia/internal/304@192.168.0.6:5060 export(call_direction=inbound)
2019-06-11 16:01:00.668719 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/304@192.168.0.6:5060 Action set(call_direction=inbound) INLINE
EXECUTE sofia/internal/304@192.168.0.6:5060 set(call_direction=inbound)
2019-06-11 16:01:00.668719 [DEBUG] mod_dptools.c:1548 SET sofia/internal/304@192.168.0.6:5060 [call_direction]=[inbound]
Dialplan: sofia/internal/304@192.168.0.6:5060 Action log([inbound routes] 404 not found ${sip_network_ip})
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/304@192.168.0.6:5060) State Change CS_ROUTING -> CS_EXECUTE
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/304@192.168.0.6:5060) State ROUTING going to sleep
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_EXECUTE (Cur 1 Tot 34)
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/304@192.168.0.6:5060) State EXECUTE
2019-06-11 16:01:00.668719 [DEBUG] mod_sofia.c:198 sofia/internal/304@192.168.0.6:5060 SOFIA EXECUTE
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:328 sofia/internal/304@192.168.0.6:5060 Standard EXECUTE
EXECUTE sofia/internal/304@192.168.0.6:5060 set(caller_id_number=304)
2019-06-11 16:01:00.668719 [DEBUG] mod_dptools.c:1548 SET sofia/internal/304@192.168.0.6:5060 [caller_id_number]=[304]
EXECUTE sofia/internal/304@192.168.0.6:5060 log([inbound routes] 404 not found 192.168.1.218)
2019-06-11 16:01:00.668719 [DEBUG] mod_dptools.c:1742 routes] 404 not found 192.168.1.218
2019-06-11 16:01:00.668719 [NOTICE] switch_core_state_machine.c:385 sofia/internal/304@192.168.0.6:5060 has executed the last dialplan instruction, hanging up.
2019-06-11 16:01:00.668719 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/304@192.168.0.6:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/304@192.168.0.6:5060) State EXECUTE going to sleep
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_HANGUP (Cur 1 Tot 34)
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/304@192.168.0.6:5060) Callstate Change RINGING -> HANGUP
2019-06-11 16:01:00.668719 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/304@192.168.0.6:5060) State HANGUP
2019-06-11 16:01:00.668719 [DEBUG] mod_sofia.c:438 Channel sofia/internal/304@192.168.0.6:5060 hanging up, cause: NORMAL_CLEARING
2019-06-11 16:01:00.668719 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2019-06-11 16:01:00.690632 [DEBUG] switch_core_state_machine.c:60 sofia/internal/304@192.168.0.6:5060 Standard HANGUP, cause: NORMAL_CLEARING
2019-06-11 16:01:00.690632 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/304@192.168.0.6:5060) State HANGUP going to sleep
2019-06-11 16:01:00.690632 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/304@192.168.0.6:5060) State Change CS_HANGUP -> CS_REPORTING
2019-06-11 16:01:00.690632 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_REPORTING (Cur 1 Tot 34)
2019-06-11 16:01:00.690632 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/304@192.168.0.6:5060) State REPORTING
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:174 sofia/internal/304@192.168.0.6:5060 Standard REPORTING, cause: NORMAL_CLEARING
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/304@192.168.0.6:5060) State REPORTING going to sleep
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/304@192.168.0.6:5060) State Change CS_REPORTING -> CS_DESTROY
2019-06-11 16:01:00.748606 [DEBUG] switch_core_session.c:1665 Session 34 (sofia/internal/304@192.168.0.6:5060) Locked, Waiting on external entities
2019-06-11 16:01:00.748606 [NOTICE] switch_core_session.c:1683 Session 34 (sofia/internal/304@192.168.0.6:5060) Ended
2019-06-11 16:01:00.748606 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/304@192.168.0.6:5060 [CS_DESTROY]
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/304@192.168.0.6:5060) Running State Change CS_DESTROY (Cur 0 Tot 34)
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/304@192.168.0.6:5060) State DESTROY
2019-06-11 16:01:00.748606 [DEBUG] mod_sofia.c:343 sofia/internal/304@192.168.0.6:5060 SOFIA DESTROY
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:181 sofia/internal/304@192.168.0.6:5060 Standard DESTROY
2019-06-11 16:01:00.748606 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/304@192.168.0.6:5060) State DESTROY going to sleep

Why i can't call between my local phones?
 
C

czbg

Member
Sep 27, 2018
33
1
8
It seems like you didn't set up inbound routes or destinations properly. What do you have there?
 
N

nufay

New Member
May 8, 2019
15
1
3
Ukraine
first pic - my only destination, for inbound calls from gateways
action 11 office-local is ring group with 3 local phones, which works fine.

set up 1 inbound route for inbound calls from the gateway, other routes were in default configuration
 

Attachments

  • 1560264710614.png
    1560264710614.png
    39.7 KB · Views: 14
  • 1560264782133.png
    1560264782133.png
    20.1 KB · Views: 14
I

Ian Oakes

Member
Oct 14, 2016
51
9
8
44
Dialplan: sofia/internal/304@192.168.0.6:5060 Action log([inbound routes] 404 not found ${sip_network_ip})

Your error shows that 304 is not found, so might want to start with that.
 
N

nufay

New Member
May 8, 2019
15
1
3
Ukraine
Ian Oakes said:
Dialplan: sofia/internal/304@192.168.0.6:5060 Action log([inbound routes] 404 not found ${sip_network_ip})

Your error shows that 304 is not found, so might want to start with that.
Click to expand...

Actually it's there
 

Attachments

  • 1560321792576.png
    1560321792576.png
    7.6 KB · Views: 8
C

czbg

Member
Sep 27, 2018
33
1
8
you should set either inbound route for 304, or inbound route for regex num or a destination. My inbound route looks like this:

Code: 
<extension name="local-in" continue="false" uuid="26e002d7-de31-45d2-9150-46fe139d8be1">
    <condition field="destination_number" expression="^(10690517[0-9])$">
        <action application="export" data="call_direction=inbound" inline="true"/>
        <action application="set" data="domain_uuid=77f94d27-ca0c-4e72-9321-ed4a18c455a0" inline="true"/>
        <action application="set" data="domain_name=example.com" inline="true"/>
        <action application="set" data="hangup_after_bridge=true"/>
        <action application="set" data="continue_on_fail=true"/>
        <action application="transfer" data="${destination_number} XML ${domain_name}"/>
    </condition>
</extension>
 
N

nufay

New Member
May 8, 2019
15
1
3
Ukraine
czbg said:
you should set either inbound route for 304, or inbound route for regex num or a destination. My inbound route looks like this:

Code: 
<extension name="local-in" continue="false" uuid="26e002d7-de31-45d2-9150-46fe139d8be1">
    <condition field="destination_number" expression="^(10690517[0-9])$">
        <action application="export" data="call_direction=inbound" inline="true"/>
        <action application="set" data="domain_uuid=77f94d27-ca0c-4e72-9321-ed4a18c455a0" inline="true"/>
        <action application="set" data="domain_name=example.com" inline="true"/>
        <action application="set" data="hangup_after_bridge=true"/>
        <action application="set" data="continue_on_fail=true"/>
        <action application="transfer" data="${destination_number} XML ${domain_name}"/>
    </condition>
</extension>
Click to expand...

Do i need to manually write dialplan rules for each extension i create?
it sounds strange
 
C

czbg

Member
Sep 27, 2018
33
1
8
that's why I used regex. afaik that's the way.. In your case I would use regex ^(3\d{2})$
 
N

nufay

New Member
May 8, 2019
15
1
3
Ukraine
czbg said:
that's why I used regex. afaik that's the way.. In your case I would use regex ^(3\d{2})$
Click to expand...
I don't quite understand, how do i need to configure it in Dialplan -> destinations.
To clarify - do i need to set up inbound routes for local calls between internal extensions?
 
Last edited:
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
Your real problem is that it looks like you have messed with the access control lists. It looks like you have added your own IPs to it, that should NOT be done. That is for carrier IPs.
 
  • Like
Reactions: nufay
N

nufay

New Member
May 8, 2019
15
1
3
Ukraine
DigitalDaz said:
Your real problem is that it looks like you have messed with the access control lists. It looks like you have added your own IPs to it, that should NOT be done. That is for carrier IPs.
Click to expand...
Yes, looks like i accidentally added lan CIDR to 'domains' ACL instead of 'lan' ACL.
Fixing it solved this strange behavior
 
Last edited:
Status
Not open for further replies.
Top Bottom