I tried the command in a cluster environment so 9999 can be on node1 and 7777 on node2 here is the log 2011-04-01 19:54:45.192621 [DEBUG] switch_ivr_originate.c:1973 variable string 0 = [presence_id=9999@boophone.com] 2011-04-01 19:54:45.193638 [NOTICE] switch_channel.c:812 New Channel sofia/internal/sip:9999@192.168.0.18:58251 [43cf3947-e9b3-4828-befc-e284dc4a9e3a] 2011-04-01 19:54:45.193638 [DEBUG] mod_sofia.c:4286 (sofia/internal/sip:9999@192.168.0.18:58251) State Change CS_NEW -> CS_INIT 2011-04-01 19:54:45.193638 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [BREAK] 2011-04-01 19:54:45.193638 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:9999@192.168.0.18:58251) Running State Change CS_INIT 2011-04-01 19:54:45.193638 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:9999@192.168.0.18:58251) State INIT 2011-04-01 19:54:45.193638 [DEBUG] mod_sofia.c:84 sofia/internal/sip:9999@192.168.0.18:58251 SOFIA INIT 2011-04-01 19:54:45.194651 [DEBUG] mod_sofia.c:124 (sofia/internal/sip:9999@192.168.0.18:58251) State Change CS_INIT -> CS_ROUTING 2011-04-01 19:54:45.194651 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [BREAK] 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:356 (sofia/internal/sip:9999@192.168.0.18:58251) State INIT going to sleep 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:9999@192.168.0.18:58251) Running State Change CS_ROUTING 2011-04-01 19:54:45.194651 [DEBUG] switch_channel.c:1668 (sofia/internal/sip:9999@192.168.0.18:58251) Callstate Change DOWN -> RINGING 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:9999@192.168.0.18:58251) State ROUTING 2011-04-01 19:54:45.194651 [DEBUG] mod_sofia.c:147 sofia/internal/sip:9999@192.168.0.18:58251 SOFIA ROUTING 2011-04-01 19:54:45.194651 [DEBUG] switch_ivr_originate.c:66 (sofia/internal/sip:9999@192.168.0.18:58251) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2011-04-01 19:54:45.194651 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [BREAK] 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:359 (sofia/internal/sip:9999@192.168.0.18:58251) State ROUTING going to sleep 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:9999@192.168.0.18:58251) Running State Change CS_CONSUME_MEDIA 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:9999@192.168.0.18:58251) State CONSUME_MEDIA 2011-04-01 19:54:45.194651 [DEBUG] switch_core_state_machine.c:378 (sofia/internal/sip:9999@192.168.0.18:58251) State CONSUME_MEDIA going to sleep 2011-04-01 19:54:45.195670 [DEBUG] sofia.c:4754 Channel sofia/internal/sip:9999@192.168.0.18:58251 entering state [calling][0] 2011-04-01 19:54:48.856682 [DEBUG] mod_nibblebill.c:572 Received request via SESSION_HEARTBEAT! 2011-04-01 19:54:48.856682 [DEBUG] mod_nibblebill.c:433 Attempting to bill at $0.03 per minute to account 9999 2011-04-01 19:54:48.856682 [DEBUG] mod_nibblebill.c:491 60 seconds passed since last bill time of 2011-04-01 19:53:48 2011-04-01 19:54:48.856682 [DEBUG] mod_nibblebill.c:498 Billing $0.030010 to 9999 (Call: 704fa1fc-7b97-40b3-ad16-b5fc9da6d667 / 0.134583 so far) 2011-04-01 19:54:48.856682 [DEBUG] mod_nibblebill.c:321 Doing update query [UPDATE accounts SET cash=cash-0.030010 WHERE id='9999'] 2011-04-01 19:54:48.944981 [DEBUG] mod_nibblebill.c:366 Doing lookup query [SELECT cash AS nibble_balance FROM accounts WHERE id='9999'] 2011-04-01 19:54:48.951074 [DEBUG] mod_nibblebill.c:376 Retrieved current balance for account 9999 (balance = 10.105113) 2011-04-01 19:55:01.857456 [DEBUG] mod_nibblebill.c:572 Received request via SESSION_HEARTBEAT! 2011-04-01 19:55:01.857456 [DEBUG] mod_nibblebill.c:433 Attempting to bill at $0.03 per minute to account 9999 2011-04-01 19:55:01.857456 [DEBUG] mod_nibblebill.c:491 60 seconds passed since last bill time of 2011-04-01 19:54:01 2011-04-01 19:55:01.857456 [DEBUG] mod_nibblebill.c:498 Billing $0.030010 to 9999 (Call: 2879366a-0478-4480-9977-8b22847be252 / 0.150150 so far) 2011-04-01 19:55:01.857456 [DEBUG] mod_nibblebill.c:321 Doing update query [UPDATE accounts SET cash=cash-0.030010 WHERE id='9999'] 2011-04-01 19:55:01.943873 [DEBUG] mod_nibblebill.c:366 Doing lookup query [SELECT cash AS nibble_balance FROM accounts WHERE id='9999'] 2011-04-01 19:55:01.949965 [DEBUG] mod_nibblebill.c:376 Retrieved current balance for account 9999 (balance = 10.075103) 2011-04-01 19:55:17.196147 [DEBUG] sofia.c:4754 Channel sofia/internal/sip:9999@192.168.0.18:58251 entering state [terminated][408] 2011-04-01 19:55:17.196147 [DEBUG] switch_channel.c:2563 (sofia/internal/sip:9999@192.168.0.18:58251) Callstate Change RINGING -> HANGUP 2011-04-01 19:55:17.196147 [NOTICE] sofia.c:5394 Hangup sofia/internal/sip:9999@192.168.0.18:58251 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 19:55:17.196147 [DEBUG] switch_channel.c:2579 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [KILL] 2011-04-01 19:55:17.196147 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [BREAK] 2011-04-01 19:55:17.196147 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:9999@192.168.0.18:58251) Running State Change CS_HANGUP 2011-04-01 19:55:17.196147 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:9999@192.168.0.18:58251) State HANGUP 2011-04-01 19:55:17.196147 [DEBUG] mod_sofia.c:451 sofia/internal/sip:9999@192.168.0.18:58251 Overriding SIP cause 504 with 408 from the other leg 2011-04-01 19:55:17.196147 [DEBUG] mod_sofia.c:457 Channel sofia/internal/sip:9999@192.168.0.18:58251 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:46 sofia/internal/sip:9999@192.168.0.18:58251 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:560 (sofia/internal/sip:9999@192.168.0.18:58251) State HANGUP going to sleep 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:351 (sofia/internal/sip:9999@192.168.0.18:58251) State Change CS_HANGUP -> CS_REPORTING 2011-04-01 19:55:17.204366 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [BREAK] 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:320 (sofia/internal/sip:9999@192.168.0.18:58251) Running State Change CS_REPORTING 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:9999@192.168.0.18:58251) State REPORTING 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:53 sofia/internal/sip:9999@192.168.0.18:58251 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/sip:9999@192.168.0.18:58251) State REPORTING going to sleep 2011-04-01 19:55:17.204366 [DEBUG] switch_core_state_machine.c:345 (sofia/internal/sip:9999@192.168.0.18:58251) State Change CS_REPORTING -> CS_DESTROY 2011-04-01 19:55:17.204366 [DEBUG] switch_core_session.c:1116 Send signal sofia/internal/sip:9999@192.168.0.18:58251 [BREAK] 2011-04-01 19:55:17.204366 [DEBUG] switch_core_session.c:1288 Session 79 (sofia/internal/sip:9999@192.168.0.18:58251) Locked, Waiting on external entities 2011-04-01 19:55:17.206396 [DEBUG] switch_ivr_originate.c:3506 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 19:55:17.206396 [ERR] switch_ivr_originate.c:2640 Cannot create outgoing channel of type [user] cause: [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 19:55:17.206396 [NOTICE] switch_core_session.c:1306 Session 79 (sofia/internal/sip:9999@192.168.0.18:58251) Ended 2011-04-01 19:55:17.206396 [DEBUG] switch_ivr_originate.c:3506 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE] 2011-04-01 19:55:17.206396 [NOTICE] switch_core_session.c:1308 Close Channel sofia/internal/sip:9999@192.168.0.18:58251 [CS_DESTROY] 2011-04-01 19:55:17.206396 [DEBUG] switch_core_state_machine.c:449 (sofia/internal/sip:9999@192.168.0.18:58251) Callstate Change HANGUP -> DOWN 2011-04-01 19:55:17.206396 [DEBUG] switch_core_state_machine.c:452 (sofia/internal/sip:9999@192.168.0.18:58251) Running State Change CS_DESTROY 2011-04-01 19:55:17.206396 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:9999@192.168.0.18:58251) State DESTROY 2011-04-01 19:55:17.206396 [DEBUG] mod_sofia.c:362 sofia/internal/sip:9999@192.168.0.18:58251 SOFIA DESTROY 2011-04-01 19:55:17.206396 [DEBUG] switch_core_state_machine.c:60 sofia/internal/sip:9999@192.168.0.18:58251 Standard DESTROY 2011-04-01 19:55:17.206396 [DEBUG] switch_core_state_machine.c:462 (sofia/internal/sip:9999@192.168.0.18:58251) State DESTROY going to sleep thanks ----- 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