[Freeswitch-users] Getting 502 Bad Gateway with 1.0.5.pre9

Thu Dec 17 10:08:37 PST 2009

I found the issue with this.  I did an svn checkout from the trunk, and then
I did a local svn export to another local folder.  For some reason, the svn
export did not include the libs/openzap folder (which was not the case when
I got 1.0.5pre8).  Must I do a separate svn export from the libs/openzap
folder?

Best Regards,
Jerry

-----Original Message-----
From: Brian West [mailto:brian at freeswitch.org] 
Sent: Wednesday, December 16, 2009 2:28 PM
To: freeswitch-users at lists.freeswitch.org
Subject: Re: [Freeswitch-users] Getting 502 Bad Gateway with 1.0.5.pre9

Need siptrace with this type "sofia profile xxxx siptrace on" replace xxxx
with your profile.

/b

On Dec 16, 2009, at 4:23 PM, Jerry Richards wrote:

> I upgraded to the latest 1.0.5pre9 and now if I try to call from an 
> internal phone to an external number on my Sangoma PRI, I get a "502 Bad
Gateway"
> reply.  Below is the console loglevel 7 output.  It says the 
> destination is out-of-order.  I'm not sure what this means.  Any help is
appreciated.
> 
> 2009-12-16 14:10:46.410656 [DEBUG] sofia.c:5285 0 acls to check for 
> proxy
> 2009-12-16 14:10:46.411629 [DEBUG] sofia.c:5303 network ip is a proxy 
> [0]
> 2009-12-16 14:10:46.411629 [DEBUG] sofia.c:5331 IP 192.168.72.32 
> Rejected by acl "domains". Falling back to Digest auth.
> 2009-12-16 14:10:46.452626 [DEBUG] sofia.c:5285 0 acls to check for 
> proxy
> 2009-12-16 14:10:46.452626 [DEBUG] sofia.c:5303 network ip is a proxy 
> [0]
> 2009-12-16 14:10:46.452626 [DEBUG] sofia.c:5331 IP 192.168.72.32 
> Rejected by acl "domains". Falling back to Digest auth.
> 2009-12-16 14:10:46.457607 [NOTICE] switch_channel.c:613 New Channel 
> sofia/internal/5381 at 192.168.72.141:5060
> [e58e763f-7688-4600-aa70-481bbc359f58]
> 2009-12-16 14:10:46.457607 [DEBUG] sofia.c:3787 Channel 
> sofia/internal/5381 at 192.168.72.141:5060 entering state [received][100]
> 2009-12-16 14:10:46.457607 [DEBUG] sofia.c:3798 Remote SDP:
> v=0
> o=TC 1100638826 1100638826 IN IP4 192.168.72.32 s=session c=IN IP4 
> 192.168.72.32 t=0 0 m=audio 1760 RTP/AVP 0 18 4 101 a=rtpmap:0 
> PCMU/8000
> a=rtpmap:18 G729/8000
> a=rtpmap:4 G723/8000
> a=rtpmap:101 telephone-event/8000/1
> a=ptime:20
> a=ptime:20
> 
> 2009-12-16 14:10:46.457607 [DEBUG] sofia.c:3923
> (sofia/internal/5381 at 192.168.72.141:5060) State Change CS_NEW -> 
> CS_INIT
> 2009-12-16 14:10:46.457607 [DEBUG] switch_core_session.c:1018 Send 
> signal sofia/internal/5381 at 192.168.72.141:5060 [BREAK]
> 2009-12-16 14:10:46.457607 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/5381 at 192.168.72.141:5060) Running State Change CS_INIT
> 2009-12-16 14:10:46.457607 [DEBUG] switch_core_state_machine.c:338
> (sofia/internal/5381 at 192.168.72.141:5060) State INIT
> 2009-12-16 14:10:46.457607 [DEBUG] mod_sofia.c:83 
> sofia/internal/5381 at 192.168.72.141:5060 SOFIA INIT
> 2009-12-16 14:10:46.457607 [DEBUG] mod_sofia.c:111
> (sofia/internal/5381 at 192.168.72.141:5060) State Change CS_INIT -> 
> CS_ROUTING
> 2009-12-16 14:10:46.457607 [DEBUG] switch_core_session.c:1018 Send 
> signal sofia/internal/5381 at 192.168.72.141:5060 [BREAK]
> 2009-12-16 14:10:46.457607 [DEBUG] switch_core_state_machine.c:338
> (sofia/internal/5381 at 192.168.72.141:5060) State INIT going to sleep
> 2009-12-16 14:10:46.457607 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/5381 at 192.168.72.141:5060) Running State Change 
> CS_ROUTING
> 2009-12-16 14:10:46.458582 [DEBUG] switch_core_state_machine.c:341
> (sofia/internal/5381 at 192.168.72.141:5060) State ROUTING
> 2009-12-16 14:10:46.458582 [DEBUG] mod_sofia.c:132 
> sofia/internal/5381 at 192.168.72.141:5060 SOFIA ROUTING
> 2009-12-16 14:10:46.458582 [DEBUG] switch_core_state_machine.c:78 
> sofia/internal/5381 at 192.168.72.141:5060 Standard ROUTING
> 2009-12-16 14:10:46.458582 [INFO] mod_dialplan_xml.c:408 Processing
> Anonymous->93491028 in context default
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 parsing 
> [default->unloop] continue=false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Regex (PASS) 
> [unloop]
> ${unroll_loops}(true) =~ /^true$/ break=on-false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Regex (FAIL) 
> [unloop]
> ${sip_looped_call}() =~ /^true$/ break=on-false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 parsing 
> [default->tod_example] continue=true
> Dialplan: day of week[4] =~ 2-6 (PASS)
> Dialplan: hour[14] =~ 9-18 (PASS)
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Date/Time Match 
> (PASS) [tod_example] break=on-false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Action 
> set(open=true)
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 parsing 
> [default->holiday_example] continue=true
> Dialplan: month[12] =~ 1 (FAIL)
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Date/Time Match 
> (FAIL) [holiday_example] break=on-false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 parsing 
> [default->Mediant1000] continue=false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Regex (FAIL) 
> [Mediant1000]
> destination_number(93491028) =~ /^8(\d+)$/ break=on-false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 parsing 
> [default->SangomaPRI] continue=false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Regex (PASS) 
> [SangomaPRI]
> destination_number(93491028) =~ /^9(\d+)$/ break=on-false
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Action
> set(effective_caller_id_number=425740${caller_id_number})
> Dialplan: sofia/internal/5381 at 192.168.72.141:5060 Action
> bridge(openzap/smg_prid/a/3491028 at g1)
> 2009-12-16 14:10:46.459538 [DEBUG] switch_core_state_machine.c:122
> (sofia/internal/5381 at 192.168.72.141:5060) State Change CS_ROUTING -> 
> CS_EXECUTE
> 2009-12-16 14:10:46.459538 [DEBUG] switch_core_session.c:1018 Send 
> signal sofia/internal/5381 at 192.168.72.141:5060 [BREAK]
> 2009-12-16 14:10:46.459538 [DEBUG] switch_core_state_machine.c:341
> (sofia/internal/5381 at 192.168.72.141:5060) State ROUTING going to sleep
> 2009-12-16 14:10:46.459538 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/5381 at 192.168.72.141:5060) Running State Change 
> CS_EXECUTE
> 2009-12-16 14:10:46.459538 [DEBUG] switch_core_state_machine.c:348
> (sofia/internal/5381 at 192.168.72.141:5060) State EXECUTE
> 2009-12-16 14:10:46.459538 [DEBUG] mod_sofia.c:181 
> sofia/internal/5381 at 192.168.72.141:5060 SOFIA EXECUTE
> 2009-12-16 14:10:46.459538 [DEBUG] switch_core_state_machine.c:159 
> sofia/internal/5381 at 192.168.72.141:5060 Standard EXECUTE EXECUTE 
> sofia/internal/5381 at 192.168.72.141:5060 set(open=true)
> 2009-12-16 14:10:46.459538 [DEBUG] mod_dptools.c:768 
> sofia/internal/5381 at 192.168.72.141:5060 SET [open]=[true] EXECUTE 
> sofia/internal/5381 at 192.168.72.141:5060
> set(effective_caller_id_number=4257405381)
> 2009-12-16 14:10:46.460549 [DEBUG] mod_dptools.c:768 
> sofia/internal/5381 at 192.168.72.141:5060 SET 
> [effective_caller_id_number]=[4257405381]
> EXECUTE sofia/internal/5381 at 192.168.72.141:5060
> bridge(openzap/smg_prid/a/3491028 at g1)
> 2009-12-16 14:10:46.479629 [ERR] mod_openzap.c:945 Invalid dial string
> 2009-12-16 14:10:46.479629 [ERR] switch_ivr_originate.c:2249 Cannot 
> create outgoing channel of type [openzap] cause: 
> [DESTINATION_OUT_OF_ORDER]
> 2009-12-16 14:10:46.479629 [DEBUG] switch_ivr_originate.c:3009 
> Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER]
> 2009-12-16 14:10:46.488521 [INFO] mod_dptools.c:2303 Originate Failed.
> Cause: DESTINATION_OUT_OF_ORDER
> 2009-12-16 14:10:46.488521 [NOTICE] mod_dptools.c:2366 Hangup 
> sofia/internal/5381 at 192.168.72.141:5060 [CS_EXECUTE] 
> [DESTINATION_OUT_OF_ORDER]
> 2009-12-16 14:10:46.488521 [DEBUG] switch_channel.c:1912 Send signal 
> sofia/internal/5381 at 192.168.72.141:5060 [KILL]
> 2009-12-16 14:10:46.488521 [DEBUG] switch_core_session.c:1018 Send 
> signal sofia/internal/5381 at 192.168.72.141:5060 [BREAK]
> 2009-12-16 14:10:46.488521 [DEBUG] switch_core_state_machine.c:348
> (sofia/internal/5381 at 192.168.72.141:5060) State EXECUTE going to sleep
> 2009-12-16 14:10:46.488521 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/5381 at 192.168.72.141:5060) Running State Change 
> CS_HANGUP
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_state_machine.c:494
> (sofia/internal/5381 at 192.168.72.141:5060) State HANGUP
> 2009-12-16 14:10:46.489603 [DEBUG] mod_sofia.c:358 Channel 
> sofia/internal/5381 at 192.168.72.141:5060 hanging up, cause:
> DESTINATION_OUT_OF_ORDER
> 2009-12-16 14:10:46.489603 [DEBUG] mod_sofia.c:421 Responding to 
> INVITE
> with: 502
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_state_machine.c:46 
> sofia/internal/5381 at 192.168.72.141:5060 Standard HANGUP, cause:
> DESTINATION_OUT_OF_ORDER
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_state_machine.c:494
> (sofia/internal/5381 at 192.168.72.141:5060) State HANGUP going to sleep
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_state_machine.c:333
> (sofia/internal/5381 at 192.168.72.141:5060) State Change CS_HANGUP -> 
> CS_REPORTING
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_session.c:1018 Send 
> signal sofia/internal/5381 at 192.168.72.141:5060 [BREAK]
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_state_machine.c:314
> (sofia/internal/5381 at 192.168.72.141:5060) Running State Change 
> CS_REPORTING
> 2009-12-16 14:10:46.489603 [DEBUG] switch_core_state_machine.c:585
> (sofia/internal/5381 at 192.168.72.141:5060) State REPORTING
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:53 
> sofia/internal/5381 at 192.168.72.141:5060 Standard REPORTING, cause:
> DESTINATION_OUT_OF_ORDER
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:585
> (sofia/internal/5381 at 192.168.72.141:5060) State REPORTING going to 
> sleep
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:327
> (sofia/internal/5381 at 192.168.72.141:5060) State Change CS_REPORTING -> 
> CS_DESTROY
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_session.c:1018 Send 
> signal sofia/internal/5381 at 192.168.72.141:5060 [BREAK]
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_session.c:1155 Session 
> 1
> (sofia/internal/5381 at 192.168.72.141:5060) Locked, Waiting on external 
> entities
> 2009-12-16 14:10:46.562662 [NOTICE] switch_core_session.c:1173 Session 
> 1
> (sofia/internal/5381 at 192.168.72.141:5060) Ended
> 2009-12-16 14:10:46.562662 [NOTICE] switch_core_session.c:1175 Close 
> Channel sofia/internal/5381 at 192.168.72.141:5060 [CS_DESTROY]
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:423
> (sofia/internal/5381 at 192.168.72.141:5060) Running State Change 
> CS_DESTROY
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/5381 at 192.168.72.141:5060) State DESTROY
> 2009-12-16 14:10:46.562662 [DEBUG] mod_sofia.c:293 
> sofia/internal/5381 at 192.168.72.141:5060 SOFIA DESTROY
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:60 
> sofia/internal/5381 at 192.168.72.141:5060 Standard DESTROY
> 2009-12-16 14:10:46.562662 [DEBUG] switch_core_state_machine.c:434
> (sofia/internal/5381 at 192.168.72.141:5060) State DESTROY going to sleep
> 
> 
> Best Regards,
> Jerry
> 
> 
> _______________________________________________
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-use
> rs
> http://www.freeswitch.org