sorry the sip trace : after this command: /usr/local/freeswitch/bin/fs_cli -x "originate user/9999999999 1111111111" ------------------------------------------------------------------------ 2011-04-01 23:33:39.673581 [DEBUG] sofia.c:4754 Channel sofia/internal/sip:99999999999@11.22.33.44:52767 entering state [calling][0] send 1385 bytes to udp/[11.22.33.44]:52767 at 03:33:40.673952: ------------------------------------------------------------------------ INVITE sip:99999999999@11.22.33.44:52767 SIP/2.0 Via: SIP/2.0/UDP 11.22.33.44:5080;rport;branch=z9hG4bK415Sta2FX5NrD Max-Forwards: 70 From: "" <sip:0000000000@11.22.33.44>;tag=S16mjZ06UgQSe To: <sip:99999999999@11.22.33.44:52767> Call-ID: 02ac42f6-92d1-4f3b-bc98-aa00d5f01af5 CSeq: 10521545 INVITE Contact: <sip:mod_sofia@11.22.33.44:5080> User-Agent: CiscoSystems-SIP-GW-UA Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 492 X-FS-Support: update_display Remote-Party-ID: <sip:0000000000@11.22.33.44>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1301682069 1301682070 IN IP4 11.22.33.44 s=FreeSWITCH c=IN IP4 11.22.33.44 t=0 0 m=audio 33150 RTP/AVP 98 0 8 3 99 100 102 103 104 9 105 5 106 101 13 a=rtpmap:98 SPEEX/16000 a=rtpmap:99 G726-16/8000 a=rtpmap:100 G726-24/8000 a=rtpmap:102 G726-32/8000 a=rtpmap:103 G726-40/8000 a=rtpmap:104 G7221/16000 a=fmtp:104 bitrate=32000 a=rtpmap:105 iLBC/8000 a=fmtp:105 mode=20 a=rtpmap:106 L16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ send 1385 bytes to udp/[11.22.33.44]:52767 at 03:33:42.673971: ------------------------------------------------------------------------ INVITE sip:99999999999@11.22.33.44:52767 SIP/2.0 Via: SIP/2.0/UDP 11.22.33.44:5080;rport;branch=z9hG4bK415Sta2FX5NrD Max-Forwards: 70 From: "" <sip:0000000000@11.22.33.44>;tag=S16mjZ06UgQSe To: <sip:99999999999@11.22.33.44:52767> Call-ID: 02ac42f6-92d1-4f3b-bc98-aa00d5f01af5 CSeq: 10521545 INVITE Contact: <sip:mod_sofia@11.22.33.44:5080> User-Agent: CiscoSystems-SIP-GW-UA Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 492 X-FS-Support: update_display Remote-Party-ID: <sip:0000000000@11.22.33.44>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1301682069 1301682070 IN IP4 11.22.33.44 s=FreeSWITCH c=IN IP4 11.22.33.44 t=0 0 m=audio 33150 RTP/AVP 98 0 8 3 99 100 102 103 104 9 105 5 106 101 13 a=rtpmap:98 SPEEX/16000 a=rtpmap:99 G726-16/8000 a=rtpmap:100 G726-24/8000 a=rtpmap:102 G726-32/8000 a=rtpmap:103 G726-40/8000 a=rtpmap:104 G7221/16000 a=fmtp:104 bitrate=32000 a=rtpmap:105 iLBC/8000 a=fmtp:105 mode=20 a=rtpmap:106 L16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ send 1385 bytes to udp/[11.22.33.44]:52767 at 03:33:46.673944: ------------------------------------------------------------------------ INVITE sip:99999999999@11.22.33.44:52767 SIP/2.0 Via: SIP/2.0/UDP 11.22.33.44:5080;rport;branch=z9hG4bK415Sta2FX5NrD Max-Forwards: 70 From: "" <sip:0000000000@11.22.33.44>;tag=S16mjZ06UgQSe To: <sip:99999999999@11.22.33.44:52767> Call-ID: 02ac42f6-92d1-4f3b-bc98-aa00d5f01af5 CSeq: 10521545 INVITE Contact: <sip:mod_sofia@11.22.33.44:5080> User-Agent: CiscoSystems-SIP-GW-UA Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 492 X-FS-Support: update_display Remote-Party-ID: <sip:0000000000@11.22.33.44>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1301682069 1301682070 IN IP4 11.22.33.44 s=FreeSWITCH c=IN IP4 11.22.33.44 t=0 0 m=audio 33150 RTP/AVP 98 0 8 3 99 100 102 103 104 9 105 5 106 101 13 a=rtpmap:98 SPEEX/16000 a=rtpmap:99 G726-16/8000 a=rtpmap:100 G726-24/8000 a=rtpmap:102 G726-32/8000 a=rtpmap:103 G726-40/8000 a=rtpmap:104 G7221/16000 a=fmtp:104 bitrate=32000 a=rtpmap:105 iLBC/8000 a=fmtp:105 mode=20 a=rtpmap:106 L16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ send 1385 bytes to udp/[11.22.33.44]:52767 at 03:33:54.673950: ------------------------------------------------------------------------ INVITE sip:99999999999@11.22.33.44:52767 SIP/2.0 Via: SIP/2.0/UDP 11.22.33.44:5080;rport;branch=z9hG4bK415Sta2FX5NrD Max-Forwards: 70 From: "" <sip:0000000000@11.22.33.44>;tag=S16mjZ06UgQSe To: <sip:99999999999@11.22.33.44:52767> Call-ID: 02ac42f6-92d1-4f3b-bc98-aa00d5f01af5 CSeq: 10521545 INVITE Contact: <sip:mod_sofia@11.22.33.44:5080> User-Agent: CiscoSystems-SIP-GW-UA Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 492 X-FS-Support: update_display Remote-Party-ID: <sip:0000000000@11.22.33.44>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1301682069 1301682070 IN IP4 11.22.33.44 s=FreeSWITCH c=IN IP4 11.22.33.44 t=0 0 m=audio 33150 RTP/AVP 98 0 8 3 99 100 102 103 104 9 105 5 106 101 13 a=rtpmap:98 SPEEX/16000 a=rtpmap:99 G726-16/8000 a=rtpmap:100 G726-24/8000 a=rtpmap:102 G726-32/8000 a=rtpmap:103 G726-40/8000 a=rtpmap:104 G7221/16000 a=fmtp:104 bitrate=32000 a=rtpmap:105 iLBC/8000 a=fmtp:105 mode=20 a=rtpmap:106 L16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ send 1385 bytes to udp/[11.22.33.44]:52767 at 03:34:10.674077: ------------------------------------------------------------------------ INVITE sip:99999999999@11.22.33.44:52767 SIP/2.0 Via: SIP/2.0/UDP 11.22.33.44:5080;rport;branch=z9hG4bK415Sta2FX5NrD Max-Forwards: 70 From: "" <sip:0000000000@11.22.33.44>;tag=S16mjZ06UgQSe To: <sip:99999999999@11.22.33.44:52767> Call-ID: 02ac42f6-92d1-4f3b-bc98-aa00d5f01af5 CSeq: 10521545 INVITE Contact: <sip:mod_sofia@11.22.33.44:5080> User-Agent: CiscoSystems-SIP-GW-UA Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE, INFO, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, precondition, path, replaces Allow-Events: talk, hold, presence, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 492 X-FS-Support: update_display Remote-Party-ID: <sip:0000000000@11.22.33.44>;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1301682069 1301682070 IN IP4 11.22.33.44 s=FreeSWITCH c=IN IP4 11.22.33.44 t=0 0 m=audio 33150 RTP/AVP 98 0 8 3 99 100 102 103 104 9 105 5 106 101 13 a=rtpmap:98 SPEEX/16000 a=rtpmap:99 G726-16/8000 a=rtpmap:100 G726-24/8000 a=rtpmap:102 G726-32/8000 a=rtpmap:103 G726-40/8000 a=rtpmap:104 G7221/16000 a=fmtp:104 bitrate=32000 a=rtpmap:105 iLBC/8000 a=fmtp:105 mode=20 a=rtpmap:106 L16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2011-04-01 23:34:11.674022 [DEBUG] sofia.c:4754 Channel sofia/internal/sip:99999999999@11.22.33.44:52767 entering state [terminated][408] 2011-04-01 23:34:11.674022 [DEBUG] switch_channel.c:2563 (sofia/internal/sip:99999999999@11.22.33.44:52767) Callstate Change RINGING -> HANGUP 2011-04-01 23:34:11.674022 [NOTICE] sofia.c:5394 Hangup sofia/internal/sip:99999999999@11.22.33.44:52767 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 23:34:11.674022 [DEBUG] switch_channel.c:2579 Send signal sofia/internal/sip:99999999999@11.22.33.44:52767 [KILL] 2011-04-01 23:34:11.674022 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:99999999999@11.22.33.44:52767 [BREAK] 2011-04-01 23:34:11.674022 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:99999999999@11.22.33.44:52767) Running State Change CS_HANGUP 2011-04-01 23:34:11.674022 [DEBUG] switch_ivr_originate.c:3506 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 23:34:11.674022 [ERR] switch_ivr_originate.c:2640 Cannot create outgoing channel of type [user] cause: [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 23:34:11.674022 [DEBUG] switch_ivr_originate.c:3506 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 23:34:11.675057 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:99999999999@11.22.33.44:52767) State HANGUP 2011-04-01 23:34:11.675057 [DEBUG] mod_sofia.c:451 sofia/internal/sip:99999999999@11.22.33.44:52767 Overriding SIP cause 504 with 408 from the other leg 2011-04-01 23:34:11.675057 [DEBUG] mod_sofia.c:457 Channel sofia/internal/sip:99999999999@11.22.33.44:52767 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:99999999999@11.22.33.44:52767 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:99999999999@11.22.33.44:52767) State HANGUP going to sleep 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/sip:99999999999@11.22.33.44:52767) State Change CS_HANGUP -> CS_REPORTING 2011-04-01 23:34:11.695371 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:99999999999@11.22.33.44:52767 [BREAK] 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:99999999999@11.22.33.44:52767) Running State Change CS_REPORTING 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:99999999999@11.22.33.44:52767) State REPORTING 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:99999999999@11.22.33.44:52767 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:99999999999@11.22.33.44:52767) State REPORTING going to sleep 2011-04-01 23:34:11.695371 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/sip:99999999999@11.22.33.44:52767) State Change CS_REPORTING -> CS_DESTROY 2011-04-01 23:34:11.695371 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:99999999999@11.22.33.44:52767 [BREAK] 2011-04-01 23:34:11.695371 [DEBUG] switch_core_session.c:1288 Session 5 (sofia/internal/sip:99999999999@11.22.33.44:52767) Locked, Waiting on external entities 2011-04-01 23:34:11.695371 [NOTICE] switch_core_session.c:1306 Session 5 (sofia/internal/sip:99999999999@11.22.33.44:52767) Ended 2011-04-01 23:34:11.695371 [NOTICE] switch_core_session.c:1308 Close Channel sofia/internal/sip:99999999999@11.22.33.44:52767 [CS_DESTROY] 2011-04-01 23:34:11.696436 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/sip:99999999999@11.22.33.44:52767) Callstate Change HANGUP -> DOWN 2011-04-01 23:34:11.696436 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:99999999999@11.22.33.44:52767) Running State Change CS_DESTROY 2011-04-01 23:34:11.696436 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:99999999999@11.22.33.44:52767) State DESTROY 2011-04-01 23:34:11.696436 [DEBUG] mod_sofia.c:362 sofia/internal/sip:99999999999@11.22.33.44:52767 SOFIA DESTROY 2011-04-01 23:34:11.696436 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:99999999999@11.22.33.44:52767 Standard DESTROY 2011-04-01 23:34:11.696436 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:99999999999@11.22.33.44:52767) State DESTROY going to sleep a ----- Original Message ----- From: Steven Ayre To: FreeSWITCH Users Help Sent: Friday, April 01, 2011 5:30 PM Subject: Re: [Freeswitch-users] originate from cli It can also be that the other side sent FS a reply saying that *it* had timed out. siptrace will also show if that's the case. On 1 April 2011 22:29, Steven Ayre <steveayre@gmail.com> wrote: It means FS sent a message and didn't get a reply (timed out). As anthm says, look at the siptrace - that'll show you what's being sent / received. -Steve On 1 April 2011 21:17, Madovsky <infos@madovsky.org> wrote: I make some test with originate from cli. /usr/local/freeswitch/bin/fs_cli -x "originate user/9999 7777 XML public" -ERR RECOVERY_ON_TIMER_EXPIRE 9999 and 7777 are ready to receive calls and I don't have any NAT. is anyone can explain what it means ? Thanks _______________________________________________ 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 ------------------------------------------------------------------------------ _______________________________________________ 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