Hi Michael, Frankly I am not sure what exactly you referring to. I am completely new to freeswitch. If you are talking about running command (I found it in online doc): TPORT_LOG=1 /usr/local/freeswitch/bin/freeswitch then there is a problem, Like I said I am running it in Windows. Running FreeSWITCH\FreeSwitchConsole.exe. Besides I have no idea what pastebin is. Only can guess it preserves the colors of debug printouts. I have instead prepared below a debug printout I manage to get in the console. Also added my comment. Please, could anyone have a look at it. Briefly, I want a simple functionality. If call comes in to my SIP provider I want it to be forwarded to another fixed external number. That is it! Seems like a straight forward task for freeswitch. The call seems to be forwarded (according to the log), but something stops it and it gets paused for 10 seconds, until busy signal and call is disconnected afterwards. Thanks in advance. Sergei Kamen ============================================================== public.xml has extension: <extension name="Forward All"> <condition field="caller_id_number" expression="^(\d+)$"> <action application="transfer" data="3472 XML default"/> </condition> </extension> and default.xml has: <extension name="Forward All"> <condition field="destination_number" expression="3472"> <action application="bridge" data="sofia/gateway/freephoneline/15191212121"/> </condition> </extension> The following printout in my console is as follows from the beginning: ------------------------------ nta: bind([::1]:5070;transport=*): No such file or directory nua: initializing SIP stack failed [SK:] could it be the error above? 2011-05-21 17:59:38.187500 [ERR] sofia.c:1533 Error Creating SIP UA for profile: internal-ipv6 2011-05-21 17:59:40.875000 [DEBUG] switch_nat.c:502 mapped public port 5080 protocol TCP to localport 5080 2011-05-21 17:59:40.875000 [DEBUG] sofia.c:1487 Created TCP nat mapping for external port 5080 2011-05-21 17:59:40.875000 [DEBUG] switch_nat.c:502 mapped public port 5070 protocol TCP to localport 5070 2011-05-21 17:59:40.875000 [DEBUG] sofia.c:1487 Created TCP nat mapping for internal port 5070 2011-05-21 17:59:40.906250 [DEBUG] sofia.c:1539 Created agent for external 2011-05-21 17:59:40.906250 [DEBUG] sofia.c:1576 Set params for external 2011-05-21 17:59:40.906250 [DEBUG] sofia.c:1599 Activated db for external 2011-05-21 17:59:40.906250 [DEBUG] sofia.c:1626 Starting thread for external 2011-05-21 17:59:40.921875 [DEBUG] sofia.c:1539 Created agent for internal 2011-05-21 17:59:40.921875 [DEBUG] sofia.c:1576 Set params for internal 2011-05-21 17:59:40.921875 [DEBUG] sofia.c:1599 Activated db for internal 2011-05-21 17:59:40.921875 [DEBUG] sofia.c:1626 Starting thread for internal 2011-05-21 17:59:41.921875 [NOTICE] sofia_reg.c:367 Registering mysipprovider 2011-05-21 17:59:44.062500 [DEBUG] sofia_reg.c:1922 Authenticating '16472222222' with 'Digest:"voip.mysipprovider.ca":16472222222:mypassword'. 2011-05-21 17:59:44.921875 [DEBUG] sofia_reg.c:331 Registered mysipprovider 2011-05-21 18:00:00.984375 [WARNING] sofia.c:4065 Ping succeeded mysipprovider with code 501 - count -1/1/1, state UP [SK:]I am calling here to my SIP provider number (16472222222) from another phone (9051212121). I expect it to forward to a third number (15191212121) with updated Caller ID of my provider. 2011-05-21 18:00:34.609375 [NOTICE] switch_channel.c:812 New Channel sofia/external/9051212121@218.165.240.142 [bc74d840-a951-458e-9eec-c70941fdd05a] 2011-05-21 18:00:34.609375 [DEBUG] sofia.c:4744 Channel sofia/external/9051212121@218.165.240.142 entering state [received][100] 2011-05-21 18:00:34.609375 [DEBUG] sofia.c:4755 Remote SDP: v=0 o=Sippy 383374256 0 IN IP4 218.165.240.142 s=- t=0 0 m=audio 35774 RTP/AVP 0 c=IN IP4 208.72.120.90 2011-05-21 18:00:34.609375 [DEBUG] sofia_glue.c:4637 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:115:32000:20:48000] 2011-05-21 18:00:34.609375 [DEBUG] sofia_glue.c:4637 Audio Codec Compare [PCMU:0:8000:20:64000]/[G7221:107:16000:20:32000] 2011-05-21 18:00:34.609375 [DEBUG] sofia_glue.c:4637 Audio Codec Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_NEW 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:338 (sofia/external/9051212121@218.165.240.142) State NEW 2011-05-21 18:00:34.609375 [DEBUG] sofia_glue.c:4637 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000] 2011-05-21 18:00:34.609375 [DEBUG] sofia_glue.c:2760 Set Codec sofia/external/9051212121@218.165.240.142 PCMU/8000 20 ms 160 samples 64000 bits 2011-05-21 18:00:34.609375 [DEBUG] sofia.c:4922 (sofia/external/9051212121@218.165.240.142) State Change CS_NEW -> CS_INIT 2011-05-21 18:00:34.609375 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_INIT 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:356 (sofia/external/9051212121@218.165.240.142) State INIT 2011-05-21 18:00:34.609375 [DEBUG] mod_sofia.c:84 sofia/external/9051212121@218.165.240.142 SOFIA INIT 2011-05-21 18:00:34.609375 [DEBUG] mod_sofia.c:124 (sofia/external/9051212121@218.165.240.142) State Change CS_INIT -> CS_ROUTING 2011-05-21 18:00:34.609375 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:356 (sofia/external/9051212121@218.165.240.142) State INIT going to sleep 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_ROUTING 2011-05-21 18:00:34.609375 [DEBUG] switch_channel.c:1668 (sofia/external/9051212121@218.165.240.142) Callstate Change DOWN -> RINGING 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:359 (sofia/external/9051212121@218.165.240.142) State ROUTING 2011-05-21 18:00:34.609375 [DEBUG] mod_sofia.c:147 sofia/external/9051212121@218.165.240.142 SOFIA ROUTING 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:77 sofia/external/9051212121@218.165.240.142 Standard ROUTING 2011-05-21 18:00:34.609375 [INFO] mod_dialplan_xml.c:331 Processing MICHAEL S <9051212121>->3472 in context public Dialplan: sofia/external/9051212121@218.165.240.142 parsing [public->Forward All] continue=false Dialplan: sofia/external/9051212121@218.165.240.142 Regex (PASS) [Forward All] caller_id_number(9051212121) =~ /^(\d+)$/ break=on-false Dialplan: sofia/external/9051212121@218.165.240.142 Action transfer(3472 XML default) 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:119 (sofia/external/9051212121@218.165.240.142) State Change CS_ROUTING -> CS_EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:359 (sofia/external/9051212121@218.165.240.142) State ROUTING going to sleep 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:366 (sofia/external/9051212121@218.165.240.142) State EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] mod_sofia.c:240 sofia/external/9051212121@218.165.240.142 SOFIA EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:157 sofia/external/9051212121@218.165.240.142 Standard EXECUTE EXECUTE sofia/external/9051212121@218.165.240.142 transfer(3472 XML default) 2011-05-21 18:00:34.609375 [DEBUG] switch_ivr.c:1600 (sofia/external/9051212121@218.165.240.142) State Change CS_EXECUTE -> CS_ROUTING 2011-05-21 18:00:34.609375 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_session.c:709 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:34.609375 [NOTICE] switch_ivr.c:1606 Transfer sofia/external/9051212121@218.165.240.142 to XML[3472@default] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:366 (sofia/external/9051212121@218.165.240.142) State EXECUTE going to sleep 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_ROUTING 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:359 (sofia/external/9051212121@218.165.240.142) State ROUTING 2011-05-21 18:00:34.609375 [DEBUG] mod_sofia.c:147 sofia/external/9051212121@218.165.240.142 SOFIA ROUTING 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:77 sofia/external/9051212121@218.165.240.142 Standard ROUTING 2011-05-21 18:00:34.609375 [INFO] mod_dialplan_xml.c:331 Processing SIDOROV S <9051212121>->3472 in context default Dialplan: sofia/external/9051212121@218.165.240.142 parsing [default->Forward All] continue=false Dialplan: sofia/external/9051212121@218.165.240.142 Regex (PASS) [Forward All] destination_number(3472) =~ /3472/ break=on-false Dialplan: sofia/external/9051212121@218.165.240.142 Action log(INFO dialing destination number) Dialplan: sofia/external/9051212121@218.165.240.142 Action bridge(sofia/gateway/mysipprovider/15191212121) 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:119 (sofia/external/9051212121@218.165.240.142) State Change CS_ROUTING -> CS_EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:359 (sofia/external/9051212121@218.165.240.142) State ROUTING going to sleep 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:366 (sofia/external/9051212121@218.165.240.142) State EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] mod_sofia.c:240 sofia/external/9051212121@218.165.240.142 SOFIA EXECUTE 2011-05-21 18:00:34.609375 [DEBUG] switch_core_state_machine.c:157 sofia/external/9051212121@218.165.240.142 Standard EXECUTE EXECUTE sofia/external/9051212121@218.165.240.142 log(INFO dialing destination number) 2011-05-21 18:00:34.609375 [INFO] mod_dptools.c:1183 dialing destination number EXECUTE sofia/external/9051212121@218.165.240.142 bridge(sofia/gateway/mysipprovider/15191212121) 2011-05-21 18:00:34.625000 [NOTICE] switch_channel.c:812 New Channel sofia/external/15191212121 [5a8e5141-6d37-4db3-b5d4-5c3d1f952bbe] 2011-05-21 18:00:34.625000 [DEBUG] mod_sofia.c:4286 (sofia/external/15191212121) State Change CS_NEW -> CS_INIT 2011-05-21 18:00:34.625000 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/15191212121 [BREAK] 2011-05-21 18:00:34.625000 [DEBUG] switch_core_state_machine.c:320 (sofia/external/15191212121) Running State Change CS_INIT 2011-05-21 18:00:34.625000 [DEBUG] switch_core_state_machine.c:356 (sofia/external/15191212121) State INIT 2011-05-21 18:00:34.625000 [DEBUG] mod_sofia.c:84 sofia/external/15191212121 SOFIA INIT [SK:]Pause starts here 2011-05-21 18:00:39.625000 [DEBUG] switch_nat.c:502 mapped public port 17090 protocol UDP to localport 17090 [SK:]I get short "busy" signal here, and hang up. The rest is "hanging up" process messages. 2011-05-21 18:00:44.421875 [DEBUG] sofia.c:4744 Channel sofia/external/9051212121@218.165.240.142 entering state [terminated][487] 2011-05-21 18:00:44.421875 [DEBUG] switch_channel.c:2563 (sofia/external/9051212121@218.165.240.142) Callstate Change RINGING -> HANGUP 2011-05-21 18:00:44.421875 [NOTICE] sofia.c:5384 Hangup sofia/external/9051212121@218.165.240.142 [CS_EXECUTE] [ORIGINATOR_CANCEL] 2011-05-21 18:00:44.421875 [DEBUG] switch_channel.c:2579 Send signal sofia/external/9051212121@218.165.240.142 [KILL] 2011-05-21 18:00:44.421875 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:44.437500 [DEBUG] switch_channel.c:2563 (sofia/external/15191212121) Callstate Change DOWN -> HANGUP 2011-05-21 18:00:44.437500 [NOTICE] switch_ivr_originate.c:3343 Hangup sofia/external/15191212121 [CS_INIT] [ORIGINATOR_CANCEL] 2011-05-21 18:00:44.437500 [DEBUG] switch_channel.c:2579 Send signal sofia/external/15191212121 [KILL] 2011-05-21 18:00:44.437500 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/15191212121 [BREAK] 2011-05-21 18:00:44.437500 [DEBUG] switch_ivr_originate.c:3500 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL] 2011-05-21 18:00:44.437500 [INFO] mod_dptools.c:2623 Originate Failed. Cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.437500 [DEBUG] switch_core_session.c:2060 sofia/external/9051212121@218.165.240.142 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:366 (sofia/external/9051212121@218.165.240.142) State EXECUTE going to sleep 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_HANGUP 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:560 (sofia/external/9051212121@218.165.240.142) State HANGUP 2011-05-21 18:00:44.437500 [DEBUG] mod_sofia.c:451 sofia/external/9051212121@218.165.240.142 Overriding SIP cause 487 with 487 from the other leg 2011-05-21 18:00:44.437500 [DEBUG] mod_sofia.c:457 Channel sofia/external/9051212121@218.165.240.142 hanging up, cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:46 sofia/external/9051212121@218.165.240.142 Standard HANGUP, cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:560 (sofia/external/9051212121@218.165.240.142) State HANGUP going to sleep 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:351 (sofia/external/9051212121@218.165.240.142) State Change CS_HANGUP -> CS_REPORTING 2011-05-21 18:00:44.437500 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:320 (sofia/external/9051212121@218.165.240.142) Running State Change CS_REPORTING 2011-05-21 18:00:44.437500 [DEBUG] switch_core_state_machine.c:620 (sofia/external/9051212121@218.165.240.142) State REPORTING 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:53 sofia/external/9051212121@218.165.240.142 Standard REPORTING, cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:620 (sofia/external/9051212121@218.165.240.142) State REPORTING going to sleep 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:345 (sofia/external/9051212121@218.165.240.142) State Change CS_REPORTING -> CS_DESTROY 2011-05-21 18:00:44.453125 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/9051212121@218.165.240.142 [BREAK] 2011-05-21 18:00:44.453125 [DEBUG] switch_core_session.c:1288 Session 1 (sofia/external/9051212121@218.165.240.142) Locked, Waiting on external entities 2011-05-21 18:00:44.453125 [NOTICE] switch_core_session.c:1306 Session 1 (sofia/external/9051212121@218.165.240.142) Ended 2011-05-21 18:00:44.453125 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/9051212121@218.165.240.142 [CS_DESTROY] 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:449 (sofia/external/9051212121@218.165.240.142) Callstate Change HANGUP -> DOWN 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:452 (sofia/external/9051212121@218.165.240.142) Running State Change CS_DESTROY 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:462 (sofia/external/9051212121@218.165.240.142) State DESTROY 2011-05-21 18:00:44.453125 [DEBUG] mod_sofia.c:362 sofia/external/9051212121@218.165.240.142 SOFIA DESTROY 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:60 sofia/external/9051212121@218.165.240.142 Standard DESTROY 2011-05-21 18:00:44.453125 [DEBUG] switch_core_state_machine.c:462 (sofia/external/9051212121@218.165.240.142) State DESTROY going to sleep 2011-05-21 18:00:44.625000 [DEBUG] switch_nat.c:502 mapped public port 17091 protocol UDP to localport 17091 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:356 (sofia/external/15191212121) State INIT going to 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:320 (sofia/external/15191212121) Running State Change CS_HANGUP 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:560 (sofia/external/15191212121) State HANGUP 2011-05-21 18:00:44.625000 [DEBUG] mod_sofia.c:451 sofia/external/15191212121 Overriding SIP cause 487 with 487 from the other leg 2011-05-21 18:00:44.625000 [DEBUG] mod_sofia.c:457 Channel sofia/external/15191212121 hanging up, cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.625000 [DEBUG] mod_sofia.c:510 Sending CANCEL to sofia/external/15191212121 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:46 sofia/external/15191212121 Standard HANGUP, cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:560 (sofia/external/15191212121) State HANGUP going to sleep 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:351 (sofia/external/15191212121) State Change CS_HANGUP -> CS_REPORTING 2011-05-21 18:00:44.625000 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/15191212121 [BREAK] 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:320 (sofia/external/15191212121) Running State Change CS_REPORTING 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:620 (sofia/external/15191212121) State REPORTING 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:53 sofia/external/15191212121 Standard REPORTING, cause: ORIGINATOR_CANCEL 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:620 (sofia/external/15191212121) State REPORTING going to sleep 2011-05-21 18:00:44.625000 [DEBUG] switch_core_state_machine.c:345 (sofia/external/15191212121) State Change CS_REPORTING -> CS_DESTROY 2011-05-21 18:00:44.625000 [DEBUG] switch_core_session.c:1116 Send signal sofia/external/15191212121 [BREAK] 2011-05-21 18:00:44.625000 [DEBUG] switch_core_session.c:1288 Session 2 (sofia/external/15191212121) Locked, Waiting on external entities 2011-05-21 18:00:44.625000 [NOTICE] switch_core_session.c:1306 Session 2 (sofia/external/15191212121) Ended 2011-05-21 18:00:44.625000 [NOTICE] switch_core_session.c:1308 Close Channel sofia/external/15191212121 [CS_DESTROY] 2011-05-21 18:00:44.640625 [DEBUG] switch_core_state_machine.c:449 (sofia/external/15191212121) Callstate Change HANGUP -> DOWN 2011-05-21 18:00:44.640625 [DEBUG] switch_core_state_machine.c:452 (sofia/external/15191212121) Running State Change CS_DESTROY 2011-05-21 18:00:44.640625 [DEBUG] switch_core_state_machine.c:462 (sofia/external/15191212121) State DESTROY 2011-05-21 18:00:44.640625 [DEBUG] mod_sofia.c:362 sofia/external/15191212121 SOFIA DESTROY 2011-05-21 18:00:49.640625 [DEBUG] switch_nat.c:562 unmapped public port 17090 protocol UDP to localport 17090 2011-05-21 18:00:54.640625 [DEBUG] switch_nat.c:562 unmapped public port 17091 protocol UDP to localport 17091 2011-05-21 18:00:54.640625 [DEBUG] switch_core_state_machine.c:60 sofia/external/15191212121 Standard DESTROY 2011-05-21 18:00:54.640625 [DEBUG] switch_core_state_machine.c:462 (sofia/external/15191212121) State DESTROY going to sleep Thanks, Sergei Kamen -- View this message in context: http://freeswitch-users.2379917.n2.nabble.com/setting-up-forward-incoming-ca... Sent from the freeswitch-users mailing list archive at Nabble.com.