The call is getting 503 Service Unavailable.
Hi,I've finished the book, and was able to send a call through to another switch that we use. There was an initial codec mismatch (G729), but after reading the debug logs (fs_cli /log 7), it was identified and after fixing that, the call went through just fine.Today, I was trying some more changes on the default config, and the call will not go through. While that is not a problem as I can always go back to the default conf, what was bothering me is that I could not find out the right cause by reading the logs. The call also did not hit the other switch. Perhaps I am not reading something right. Can someone please help me identify what part of the logs below are showing where the calls are failing?The log is given below my signature. I changed my IPs and dialed number. Sorry for the inconvenience.RegardsHASSAN2010-08-04 13:06:47.459004 [DEBUG] sofia.c:6000 IP 192.168.254.10 Rejected by acl "domains". Falling back to Digest auth.2010-08-04 13:06:48.853933 [DEBUG] sofia.c:6000 IP 192.168.254.10 Rejected by acl "domains". Falling back to Digest auth.2010-08-04 13:06:48.855161 [NOTICE] switch_channel.c:779 New Channel sofia/internal/hassan@a.b.c.d [3b01cb99-20dd-4a9d-8084-2f2e16a5aee6]2010-08-04 13:06:48.855161 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/hassan@a.b.c.d) Running State Change CS_NEW2010-08-04 13:06:48.855161 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/hassan@a.b.c.d) State NEW2010-08-04 13:06:48.856895 [DEBUG] sofia.c:6823 Setting NAT mode based on nat.auto2010-08-04 13:06:48.856895 [DEBUG] sofia.c:4318 Channel sofia/internal/hassan@a.b.c.d entering state [received][100]2010-08-04 13:06:48.856895 [DEBUG] sofia.c:4329 Remote SDP:v=0o=- 9 2 IN IP4 192.168.254.10s=CounterPath Briac=IN IP4 192.168.254.10t=0 0m=audio 63242 RTP/AVP 18 101a=rtpmap:18 G729/8000a=fmtp:18 annexb=yesa=rtpmap:101 telephone-event/8000a=fmtp:101 0-15a=alt:1 2 : wsPFY2UY ge45TD7O a1.b1.c1.d1 63242a=alt:2 1 : mCzsWRNJ nH/GgDGG 192.168.254.10 63242a=x-rtp-session-id:C59D45BA9189497CB4C041AC656702E22010-08-04 13:06:48.856895 [DEBUG] sofia_glue.c:3845 Audio Codec Compare [G729:18:8000:20]/[G729:18:8000:20]2010-08-04 13:06:48.856895 [DEBUG] sofia_glue.c:2442 Set Codec sofia/internal/hassan@a.b.c.d G729/8000 20 ms 160 samples2010-08-04 13:06:48.856895 [DEBUG] sofia_glue.c:3941 Set 2833 dtmf send/recv payload to 1012010-08-04 13:06:48.856895 [DEBUG] sofia.c:4476 (sofia/internal/hassan@a.b.c.d) State Change CS_NEW -> CS_INIT2010-08-04 13:06:48.856895 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/hassan@a.b.c.d [BREAK]2010-08-04 13:06:48.856895 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/hassan@a.b.c.d) Running State Change CS_INIT2010-08-04 13:06:48.856895 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/hassan@a.b.c.d) State INIT2010-08-04 13:06:48.856895 [DEBUG] mod_sofia.c:83 sofia/internal/hassan@a.b.c.d SOFIA INIT2010-08-04 13:06:48.856895 [DEBUG] mod_sofia.c:119 (sofia/internal/hassan@a.b.c.d) State Change CS_INIT -> CS_ROUTING2010-08-04 13:06:48.856895 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/hassan@a.b.c.d [BREAK]2010-08-04 13:06:48.856895 [DEBUG] switch_core_state_machine.c:338 (sofia/internal/hassan@a.b.c.d) State INIT going to sleep2010-08-04 13:06:48.856895 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/hassan@a.b.c.d) Running State Change CS_ROUTING2010-08-04 13:06:48.856895 [DEBUG] switch_channel.c:1512 (sofia/internal/hassan@a.b.c.d) Callstate Change DOWN -> RINGING2010-08-04 13:06:48.856895 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/hassan@a.b.c.d) State ROUTING2010-08-04 13:06:48.856895 [DEBUG] mod_sofia.c:142 sofia/internal/hassan@a.b.c.d SOFIA ROUTING2010-08-04 13:06:48.856895 [DEBUG] switch_core_state_machine.c:77 sofia/internal/hassan@a.b.c.d Standard ROUTING2010-08-04 13:06:48.856895 [INFO] mod_dialplan_xml.c:331 Processing hassan->0111234567890 in context sky189Dialplan: sofia/internal/hassan@a.b.c.d parsing [sky189->dial_sky189] continue=falseDialplan: sofia/internal/hassan@a.b.c.d Regex (PASS) [dial_sky189] destination_number(0111234567890) =~ /^011(\d+)$/ break=on-falseDialplan: sofia/internal/hassan@a.b.c.d Action set(effective_caller_id_number=${outbound_caller_id_number})Dialplan: sofia/internal/hassan@a.b.c.d Action set(effective_caller_id_name=${outbound_caller_id_name})Dialplan: sofia/internal/hassan@a.b.c.d Action bridge(sofia/external/1234567890@sky189)2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:119 (sofia/internal/hassan@a.b.c.d) State Change CS_ROUTING -> CS_EXECUTE2010-08-04 13:06:48.858888 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/hassan@a.b.c.d [BREAK]2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:341 (sofia/internal/hassan@a.b.c.d) State ROUTING going to sleep2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/hassan@a.b.c.d) Running State Change CS_EXECUTE2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/hassan@a.b.c.d) State EXECUTE2010-08-04 13:06:48.858888 [DEBUG] mod_sofia.c:235 sofia/internal/hassan@a.b.c.d SOFIA EXECUTE2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:157 sofia/internal/hassan@a.b.c.d Standard EXECUTEEXECUTE sofia/internal/hassan@a.b.c.d set(effective_caller_id_number=)2010-08-04 13:06:48.858888 [DEBUG] mod_dptools.c:854 sofia/internal/hassan@a.b.c.d SET [effective_caller_id_number]=[UNDEF]EXECUTE sofia/internal/hassan@a.b.c.d set(effective_caller_id_name=)2010-08-04 13:06:48.858888 [DEBUG] mod_dptools.c:854 sofia/internal/hassan@a.b.c.d SET [effective_caller_id_name]=[UNDEF]EXECUTE sofia/internal/hassan@a.b.c.d bridge(sofia/external/1234567890@sky189)2010-08-04 13:06:48.858888 [NOTICE] switch_channel.c:779 New Channel sofia/external/1234567890@sky189 [cfbd2d4f-87fc-4c59-b320-2290a5a076b3]2010-08-04 13:06:48.858888 [DEBUG] mod_sofia.c:3892 (sofia/external/1234567890@sky189) State Change CS_NEW -> CS_INIT2010-08-04 13:06:48.858888 [DEBUG] switch_core_session.c:1039 Send signal sofia/external/1234567890@sky189 [BREAK]2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:314 (sofia/external/1234567890@sky189) Running State Change CS_INIT2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:338 (sofia/external/1234567890@sky189) State INIT2010-08-04 13:06:48.858888 [DEBUG] mod_sofia.c:83 sofia/external/1234567890@sky189 SOFIA INIT2010-08-04 13:06:48.858888 [DEBUG] mod_sofia.c:119 (sofia/external/1234567890@sky189) State Change CS_INIT -> CS_ROUTING2010-08-04 13:06:48.858888 [DEBUG] switch_core_session.c:1039 Send signal sofia/external/1234567890@sky189 [BREAK]2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:338 (sofia/external/1234567890@sky189) State INIT going to sleep2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:314 (sofia/external/1234567890@sky189) Running State Change CS_ROUTING2010-08-04 13:06:48.858888 [DEBUG] switch_channel.c:1512 (sofia/external/1234567890@sky189) Callstate Change DOWN -> RINGING2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:341 (sofia/external/1234567890@sky189) State ROUTING2010-08-04 13:06:48.858888 [DEBUG] mod_sofia.c:142 sofia/external/1234567890@sky189 SOFIA ROUTING2010-08-04 13:06:48.858888 [DEBUG] switch_ivr_originate.c:66 (sofia/external/1234567890@sky189) State Change CS_ROUTING -> CS_CONSUME_MEDIA2010-08-04 13:06:48.858888 [DEBUG] switch_core_session.c:1039 Send signal sofia/external/1234567890@sky189 [BREAK]2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:341 (sofia/external/1234567890@sky189) State ROUTING going to sleep2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:314 (sofia/external/1234567890@sky189) Running State Change CS_CONSUME_MEDIA2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:360 (sofia/external/1234567890@sky189) State CONSUME_MEDIA2010-08-04 13:06:48.858888 [DEBUG] switch_core_state_machine.c:360 (sofia/external/1234567890@sky189) State CONSUME_MEDIA going to sleep2010-08-04 13:06:48.858888 [DEBUG] sofia.c:4318 Channel sofia/external/1234567890@sky189 entering state [calling][0]2010-08-04 13:06:48.861065 [DEBUG] sofia.c:4318 Channel sofia/external/1234567890@sky189 entering state [terminated][503]2010-08-04 13:06:48.861065 [DEBUG] switch_channel.c:2309 (sofia/external/1234567890@sky189) Callstate Change RINGING -> HANGUP2010-08-04 13:06:48.861065 [NOTICE] sofia.c:4932 Hangup sofia/external/1234567890@sky189 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]2010-08-04 13:06:48.861065 [DEBUG] switch_channel.c:2325 Send signal sofia/external/1234567890@sky189 [KILL]2010-08-04 13:06:48.861065 [DEBUG] switch_core_session.c:1039 Send signal sofia/external/1234567890@sky189 [BREAK]2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:314 (sofia/external/1234567890@sky189) Running State Change CS_HANGUP2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:535 (sofia/external/1234567890@sky189) State HANGUP2010-08-04 13:06:48.861065 [DEBUG] mod_sofia.c:447 sofia/external/1234567890@sky189 Overriding SIP cause 503 with 503 from the other leg2010-08-04 13:06:48.861065 [DEBUG] mod_sofia.c:453 Channel sofia/external/1234567890@sky189 hanging up, cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:46 sofia/external/1234567890@sky189 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:535 (sofia/external/1234567890@sky189) State HANGUP going to sleep2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:333 (sofia/external/1234567890@sky189) State Change CS_HANGUP -> CS_REPORTING2010-08-04 13:06:48.861065 [DEBUG] switch_core_session.c:1039 Send signal sofia/external/1234567890@sky189 [BREAK]2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:314 (sofia/external/1234567890@sky189) Running State Change CS_REPORTING2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:595 (sofia/external/1234567890@sky189) State REPORTING2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:53 sofia/external/1234567890@sky189 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:595 (sofia/external/1234567890@sky189) State REPORTING going to sleep2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:327 (sofia/external/1234567890@sky189) State Change CS_REPORTING -> CS_DESTROY2010-08-04 13:06:48.861065 [DEBUG] switch_core_session.c:1039 Send signal sofia/external/1234567890@sky189 [BREAK]2010-08-04 13:06:48.861065 [DEBUG] switch_ivr_originate.c:3431 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]2010-08-04 13:06:48.861065 [INFO] mod_dptools.c:2393 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.861065 [DEBUG] switch_channel.c:2309 (sofia/internal/hassan@a.b.c.d) Callstate Change RINGING -> HANGUP2010-08-04 13:06:48.861065 [NOTICE] mod_dptools.c:2456 Hangup sofia/internal/hassan@a.b.c.d [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]2010-08-04 13:06:48.861065 [DEBUG] switch_channel.c:2325 Send signal sofia/internal/hassan@a.b.c.d [KILL]2010-08-04 13:06:48.861065 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/hassan@a.b.c.d [BREAK]2010-08-04 13:06:48.861065 [DEBUG] switch_core_session.c:1905 sofia/internal/hassan@a.b.c.d skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:348 (sofia/internal/hassan@a.b.c.d) State EXECUTE going to sleep2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/hassan@a.b.c.d) Running State Change CS_HANGUP2010-08-04 13:06:48.861065 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/hassan@a.b.c.d) State HANGUP2010-08-04 13:06:48.861065 [DEBUG] mod_sofia.c:447 sofia/internal/hassan@a.b.c.d Overriding SIP cause 503 with 503 from the other leg2010-08-04 13:06:48.861065 [DEBUG] mod_sofia.c:453 Channel sofia/internal/hassan@a.b.c.d hanging up, cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.861065 [DEBUG] switch_core_session.c:1202 Session 11 (sofia/external/1234567890@sky189) Locked, Waiting on external entities2010-08-04 13:06:48.861065 [NOTICE] switch_core_session.c:1220 Session 11 (sofia/external/1234567890@sky189) Ended2010-08-04 13:06:48.862912 [NOTICE] switch_core_session.c:1222 Close Channel sofia/external/1234567890@sky189 [CS_DESTROY]2010-08-04 13:06:48.862912 [DEBUG] switch_core_state_machine.c:427 (sofia/external/1234567890@sky189) Callstate Change HANGUP -> DOWN2010-08-04 13:06:48.862912 [DEBUG] switch_core_state_machine.c:430 (sofia/external/1234567890@sky189) Running State Change CS_DESTROY2010-08-04 13:06:48.862912 [DEBUG] switch_core_state_machine.c:440 (sofia/external/1234567890@sky189) State DESTROY2010-08-04 13:06:48.862912 [DEBUG] mod_sofia.c:358 sofia/external/1234567890@sky189 SOFIA DESTROY2010-08-04 13:06:48.862912 [DEBUG] switch_core_state_machine.c:60 sofia/external/1234567890@sky189 Standard DESTROY2010-08-04 13:06:48.862912 [DEBUG] switch_core_state_machine.c:440 (sofia/external/1234567890@sky189) State DESTROY going to sleep2010-08-04 13:06:48.864893 [DEBUG] mod_sofia.c:515 Responding to INVITE with: 5032010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:46 sofia/internal/hassan@a.b.c.d Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/hassan@a.b.c.d) State HANGUP going to sleep2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:333 (sofia/internal/hassan@a.b.c.d) State Change CS_HANGUP -> CS_REPORTING2010-08-04 13:06:48.864893 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/hassan@a.b.c.d [BREAK]2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:314 (sofia/internal/hassan@a.b.c.d) Running State Change CS_REPORTING2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/hassan@a.b.c.d) State REPORTING2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:53 sofia/internal/hassan@a.b.c.d Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:595 (sofia/internal/hassan@a.b.c.d) State REPORTING going to sleep2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:327 (sofia/internal/hassan@a.b.c.d) State Change CS_REPORTING -> CS_DESTROY2010-08-04 13:06:48.864893 [DEBUG] switch_core_session.c:1039 Send signal sofia/internal/hassan@a.b.c.d [BREAK]2010-08-04 13:06:48.864893 [DEBUG] switch_core_session.c:1202 Session 10 (sofia/internal/hassan@a.b.c.d) Locked, Waiting on external entities2010-08-04 13:06:48.864893 [NOTICE] switch_core_session.c:1220 Session 10 (sofia/internal/hassan@a.b.c.d) Ended2010-08-04 13:06:48.864893 [NOTICE] switch_core_session.c:1222 Close Channel sofia/internal/hassan@a.b.c.d [CS_DESTROY]2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:427 (sofia/internal/hassan@a.b.c.d) Callstate Change HANGUP -> DOWN2010-08-04 13:06:48.864893 [DEBUG] switch_core_state_machine.c:430 (sofia/internal/hassan@a.b.c.d) Running State Change CS_DESTROY2010-08-04 13:06:48.866921 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/hassan@a.b.c.d) State DESTROY2010-08-04 13:06:48.866921 [DEBUG] mod_sofia.c:358 sofia/internal/hassan@a.b.c.d SOFIA DESTROY2010-08-04 13:06:48.866921 [DEBUG] switch_core_state_machine.c:60 sofia/internal/hassan@a.b.c.d Standard DESTROY2010-08-04 13:06:48.866921 [DEBUG] switch_core_state_machine.c:440 (sofia/internal/hassan@a.b.c.d) State DESTROY going to sleep
_______________________________________________
FreeSWITCH-users mailing list
FreeSWITCH-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org