[Freeswitch-dev] Question about placing call needed time

[Georgi Stefanov]

 Hello All,

I have a small question about time needed to place call initiated with originate command. I hope someone to give me some clues, because I am stucked

Here is the test

FreeSwitch2 dialplan:
public: blind transfer to default
  <extension name="public_did">
    <condition field="destination_number" expression="">
      <action application="set" data="domain_name=$${domain}"/>
      <action application="bridge" data="user/${destination_number}"/>
    </condition>
  </extension>


default: just play a pretty music
    <extension name="Local_Extension">
      <condition field="destination_number" expression="^(10[01][0-9])$">
        <action application="export" data="dialed_extension=$1"/>
        <action application="answer"/>
        <action application="playback" data="/usr/local/freeswitch/sounds/music/8000/ponce-preludio-in-e-major.wav"/>
      </condition>
    </extension>

FreeSwitch1
Using mod_event_socket I connect to FS1 and pass 20 commands like (20 connections):
originating from FS1 to user to FS2 - I am using "originate sofia/internal/1000 at 10.101.3.60 6001"
for user 1000 til 1020

As result I have 20 calls in FS2
This is cool for now :-)

Here comes the question arised from looking FS2 logs:
root at GeorgiStefanov:/usr/local/freeswitch/log# grep "NEW RTP SESSION CREATING" freeswitch.log 
2013-07-05 17:46:34.897918 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.897918 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.897918 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.917913 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.917913 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.917913 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.917913 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.937911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.957911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.957911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
2013-07-05 17:46:34.957911 [CRIT] switch_rtp.c:1907 NEW RTP SESSION CREATING
root at GeorgiStefanov:/usr/local/freeswitch/log# grep "NEW RTP SESSION CREATING" freeswitch.log | wc -l
20
root at GeorgiStefanov:/usr/local/freeswitch/log# grep " Correct ip/port confirmed" freeswitch.log 
2013-07-05 17:46:36.857908 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:36.857908 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:38.077915 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:38.077915 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:39.317915 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:39.317915 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:40.557916 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:40.557916 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:41.777917 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:41.777917 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:42.977908 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:42.977908 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:43.617914 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:43.617914 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:45.477914 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:45.477914 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:46.657910 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:46.677908 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:47.297931 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
2013-07-05 17:46:47.297931 [DEBUG] switch_rtp.c:3706 Correct ip/port confirmed.
root at GeorgiStefanov:/usr/local/freeswitch/log# grep " Correct ip/port confirmed" freeswitch.log | wc -l
20

I have modified switch_rtp.c I have added log "NEW RTP SESSION CREATING" in very begging of function switch_rtp_create - just want to know when media connection preparation is started

Does anybody can help me to understand the debug "Correct ip/port confirmed." info.
I am worried about the not so much of these 10 sec latency, but the sequence I thought they should be paralel, not one after another.

What is FS saying with "Correct ip/port confirmed."?
Does FS respond in paralel to all calls?