rendered paste bodyScript started on mar 24 jui 2007 17:32:28 CEST
svidev06b:~# freeswitch
2007-07-24 17:32:33 [CONSOLE] switch_core.c:563 switch_core_init_and_modload() Bringing up environment.
2007-07-24 17:32:33 [CONSOLE] switch_core.c:564 switch_core_init_and_modload() Loading Modules.
2007-07-24 17:32:33 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_console]
2007-07-24 17:32:33 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_enum]
2007-07-24 17:32:33 [NOTICE] switch_loadable_module.c:188 switch_loadable_module_process() Adding Dialplan 'enum'
2007-07-24 17:32:33 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'enum'
2007-07-24 17:32:33 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'enum'
PortAudio version number = 1899
PortAudio version text = 'PortAudio V19-devel'
Number of devices = 0
--------------------------------------------------------------------------------
2007-07-24 17:32:33 [ERR] mod_portaudio.c:936 load_config() Cannot find an input device!
2007-07-24 17:32:33 [ERR] mod_portaudio.c:946 load_config() Cannot find an input device!
2007-07-24 17:32:33 [ERR] switch_loadable_module.c:714 switch_loadable_module_load_file() Error Loading module /usr/local/freeswitch/mod/mod_portaudio.so
**Module load routine returned an error**
2007-07-24 17:32:33 [ERR] switch_loadable_module.c:714 switch_loadable_module_load_file() Error Loading module /usr/local/freeswitch/mod/mod_alsa.so
**/usr/local/freeswitch/mod/mod_alsa.so: cannot open shared object file: No such file or directory**
2007-07-24 17:32:33 [NOTICE] sofia.c:957 config_sofia() Adding Alias [default] for profile [mydomain.com]
2007-07-24 17:32:33 [NOTICE] sofia.c:968 config_sofia() Started Profile mydomain.com [sofia_reg_mydomain.com]
su_port_create(0x8066288): epoll_create() => 0: OK
su_socket_port_init(0x8066288, 0x426862c0) called
su_pthread_port_init(0x8066288, 0x426862c0) called
2007-07-24 17:32:33 [DEBUG] sofia.c:281 sofia_profile_thread_run() Creating agent for mydomain.com
nua: nua_create: entering
su_port_create(0x8090ac0): epoll_create() => 0: OK
su_socket_port_init(0x8090ac0, 0x426862c0) called
su_pthread_port_init(0x8090ac0, 0x426862c0) called
nua: nua_stack_init: entering
nua: nua_stack_set_params: entering
soa_create("default", 0x808e4e8, 0x808ed68) called
soa_set_params(static::0x808e7c0, ...) called
nta_agent_create: initialized hash tables
nta_agent_create: initialized transports
nta_agent_create: initialized random identifiers
nta_agent_create: initialized timer
nta_agent_create: initialized resolver
tport_create(): 0x808fc48
nta: master transport created
tport_bind_server(0x808fc48) to */10.133.92.53:5060/sip
tport_bind_server(0x808fc48): calling tport_listen for udp
tport_alloc_primary(0x808fc48): new primary tport 0x8091138
tport_listen(0x8091138): listening at udp/10.133.92.53:5060/sip
tport_bind_server(0x808fc48): calling tport_listen for tcp
tport_alloc_primary(0x808fc48): new primary tport 0x80913c0
tport_listen(0x80913c0): listening at tcp/10.133.92.53:5060/sip
nta: bound to (10.133.92.53:5060;transport=*)
nta: agent_init_via: SIP/2.0/udp 10.133.92.53 (sip)
nta: agent_init_via: SIP/2.0/tcp 10.133.92.53 (sip)
nta: Via fields initialized
nta: Contact header created
nua_register: Adding contact URL '10.133.92.53' to list.
2007-07-24 17:32:33 [DEBUG] mod_sofia.c:1491 mod_sofia_load() Waiting for profiles to start
2007-07-24 17:32:33 [DEBUG] sofia.c:302 sofia_profile_thread_run() Created agent for mydomain.com
nua: nua_set_params: entering
nua((nil)): signal r_set_params
2007-07-24 17:32:33 [DEBUG] sofia.c:320 sofia_profile_thread_run() Set params for mydomain.com
2007-07-24 17:32:33 [DEBUG] sofia.c:343 sofia_profile_thread_run() activated db for mydomain.com
2007-07-24 17:32:33 [DEBUG] sofia.c:366 sofia_profile_thread_run() Starting thread for mydomain.com
nua((nil)): recv r_set_params
nua((nil)): signal r_set_params
nua: nua_stack_set_params: entering
soa_set_params(static::0x808e7c0, ...) called
nua((nil)): event r_set_params 200 OK
nua: nua_event: entering
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_sofia]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_commands]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_conference]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_dptools]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_dialplan_xml]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_g711]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_gsm]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_amr]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_l16]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_sndfile]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_native_file]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_softtimer]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_say_en]
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:138 switch_loadable_module_process() Adding Endpoint 'sofia'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'sofia'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:339 switch_loadable_module_process() Adding Chat interface 'sip'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:379 switch_loadable_module_process() Adding Management interface 'mod_sofia' OID[.1.3.6.1.4.1.27880.1]
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'originate'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'tone_detect'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'killchan'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'reloadxml'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'unload'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'load'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'transfer'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'pause'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'break'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'show'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'status'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'uuid_bridge'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'session_displace'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'session_record'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'broadcast'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'hold'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'media'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'fsctl'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'help'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'version'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'sched_hangup'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'sched_broadcast'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'sched_transfer'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'sched_api'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'sched_del'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'xml_wrap'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'conference'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'conference_set_auto_outcall'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'conference'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:339 switch_loadable_module_process() Adding Chat interface 'conf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'privacy'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'transfer'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'sleep'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'strftime'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'phrase'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'eval'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'pre_answer'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'answer'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'hangup'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'log'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'info'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'event'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'export'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'set'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'unset'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'ring_ready'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'break'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'detect_speech'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'ivr'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'redirect'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'reject'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'queue_dtmf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'sched_hangup'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'sched_broadcast'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'sched_transfer'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'execute_extension'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'stop_dtmf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'start_dtmf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'stop_tone_detect'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'fax_detect'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'tone_detect'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'echo'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'park'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'gentones'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'playback'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'stop_record_session'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'record_session'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'record'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'stop_displace_session'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'displace_session'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'speak'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'bridge'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:224 switch_loadable_module_process() Adding Application 'system'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'strepoch'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'chat'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'strftime'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:244 switch_loadable_module_process() Adding API Function 'presence'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:188 switch_loadable_module_process() Adding Dialplan 'XML'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 10ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 30ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 60ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 120ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMA' (g711 alaw) 8000hz 10ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMA' (g711 alaw) 8000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMA' (g711 alaw) 8000hz 30ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMA' (g711 alaw) 8000hz 60ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'PCMA' (g711 alaw) 8000hz 120ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'GSM' (gsm) 8000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'AMR_NB' (GSM-AMR) 8000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 10ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 30ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 60ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 120ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 16000hz 10ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 16000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 16000hz 30ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 16000hz 60ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 120ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 22050hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 32000hz 10ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 32000hz 20ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 32000hz 30ms
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:164 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 32000hz 60ms
2007-07-24 17:32:35 [INFO] mod_sndfile.c:274 setup_formats()
LibSndFile Version : libsndfile-1.0.17 Supported Formats
================================================================================
AIFF (Apple/SGI) (extension "aiff")
AU (Sun/NeXT) (extension "au")
AVR (Audio Visual Research) (extension "avr")
CAF (Apple Core Audio File) (extension "caf")
HTK (HMM Tool Kit) (extension "htk")
IFF (Amiga IFF/SVX8/SV16) (extension "iff")
MAT4 (GNU Octave 2.0 / Matlab 4.2) (extension "mat")
MAT5 (GNU Octave 2.1 / Matlab 5.0) (extension "mat")
PAF (Ensoniq PARIS) (extension "paf")
PVF (Portable Voice Format) (extension "pvf")
RAW (header-less) (extension "raw")
SD2 (Sound Designer II) (extension "sd2")
SDS (Midi Sample Dump Standard) (extension "sds")
SF (Berkeley/IRCAM/CARL) (extension "sf")
VOC (Creative Labs) (extension "voc")
W64 (SoundFoundry WAVE 64) (extension "w64")
WAV (Microsoft) (extension "wav")
WAV (NIST Sphere) (extension "wav")
WAVEX (Microsoft) (extension "wav")
XI (FastTracker 2) (extension "xi")
================================================================================
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'aiff'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'au'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'avr'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'caf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'htk'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'iff'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'mat'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'paf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'pvf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'raw'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'sd2'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'sds'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'sf'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'voc'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'w64'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'wav'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'xi'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'r8'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'r16'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'r24'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'r32'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'gsm'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'ul'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'al'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'PCMA'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'L16'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'PCMU'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'GSM'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:266 switch_loadable_module_process() Adding File Format 'AMR_NB'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:206 switch_loadable_module_process() Adding Timer 'soft'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:357 switch_loadable_module_process() Adding Say interface 'en'
2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:357 switch_loadable_module_process() Adding Say interface 'es'
2007-07-24 17:32:35 [DEBUG] zap_io.c:1743 load_config() found config for span
2007-07-24 17:32:35 [DEBUG] zap_io.c:1763 load_config() created span 1 of type zt
2007-07-24 17:32:35 [DEBUG] zap_io.c:1776 load_config() span 1 [name]=[OpenZAP]
2007-07-24 17:32:35 [DEBUG] zap_io.c:1776 load_config() span 1 [trunk_type]=[e1]
2007-07-24 17:32:35 [DEBUG] zap_io.c:1780 load_config() setting trunk type to 'E1'
2007-07-24 17:32:35 [DEBUG] zap_io.c:1776 load_config() span 1 [b-channel]=[1-15,17-31]
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:1 fd:20
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:2 fd:21
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:3 fd:22
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:4 fd:23
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:5 fd:24
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:6 fd:25
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:7 fd:26
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:8 fd:27
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:9 fd:28
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:10 fd:29
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:11 fd:30
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:12 fd:31
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:13 fd:32
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:14 fd:33
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:15 fd:34
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:16 fd:35
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:17 fd:36
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:18 fd:37
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:19 fd:38
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:20 fd:39
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:21 fd:40
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:22 fd:41
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:23 fd:42
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:24 fd:43
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:25 fd:44
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:26 fd:45
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:27 fd:46
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:28 fd:47
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:29 fd:48
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:30 fd:49
2007-07-24 17:32:35 [DEBUG] zap_io.c:1776 load_config() span 1 [d-channel]=[16]
2007-07-24 17:32:35 [INFO] zap_zt.c:168 zt_open_range() configuring device /dev/zap/channel as OpenZAP device 1:31 fd:50
2007-07-24 17:32:35 [DEBUG] zap_io.c:1776 load_config() span 1 [number]=[1]
2007-07-24 17:32:35 [INFO] zap_io.c:1847 load_config() Configured 31 channel(s)
2007-07-24 17:32:35 [DEBUG] zap_isdn.c:679 zap_isdn_configure_span() opening d-channel #0 1:31
2007-07-24 17:32:35 [DEBUG] zap_isdn.c:566 zap_isdn_run() ISDN thread starting.
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:736 switch_loadable_module_load_file() Successfully Loaded [mod_openzap]
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:1003 switch_loadable_module_init() open of post_load_modules.conf failed
2007-07-24 17:32:35 [CONSOLE] switch_loadable_module.c:116 switch_loadable_module_runtime() Starting runtime thread for mod_softtimer
2007-07-24 17:32:35 [CONSOLE] switch_core.c:576 switch_core_init_and_modload()
FreeSWITCH Version 1.0.5468 Started.
Crash Protection [Disabled]
Max Sessions[1000]
freeswitch@svidev06b> 2007-07-24 17:32:35 [NOTICE] switch_loadable_module.c:138 switch_loadable_module_process() Adding Endpoint 'openzap'
freeswitch@svidev06b> tport_wakeup_pri(0x8091138): events IN
tport_recv_event(0x8091138)
tport_recv_iovec(0x8091138) msg 0x8091d18 from (udp/10.133.92.53:5060) has 908 bytes, veclen = 1
recv 908 bytes from udp/[10.60.2.20]:21778 at 15:33:00.994551:
------------------------------------------------------------------------
INVITE sip:5399@svidev06b.tst33.cvf SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-1577cc39c57f511c-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=3b66ed23
Call-ID: YTMwZTgzYjI3NTRmNWUyYjI0YTcxYWE2MjI3ZjZiMjg.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 369
v=0
o=- 5 2 IN IP4 10.60.2.20
s=CounterPath X-Lite 3.0
c=IN IP4 10.60.2.20
t=0 0
m=audio 48830 RTP/AVP 100 106 0 105 8 101
a=fmtp:101 0-15
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
m=video 23838 RTP/AVP 34
a=fmtp:34 QCIF=1 MaxBR=1960
a=rtpmap:34 H263/90000
a=sendrecv
------------------------------------------------------------------------
tport_deliver(0x8091138): msg 0x8091d18 (908 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received INVITE sip:5399@svidev06b.tst33.cvf SIP/2.0 (CSeq 1)
nta: INVITE (1) going to a default leg
nta: timer set to 200 ms
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
nua: nua_stack_set_params: entering
soa_clone(static::0x808e7c0, 0x808e4e8, 0x80985a8) called
soa_set_params(static::0x80aef90, ...) called
soa_set_params(static::0x80aef90, ...) called
nta_leg_create(0x809ad18)
soa_init_offer_answer(static::0x80aef90) called
soa_set_remote_sdp(static::0x80aef90, (nil), 0x80abd8b, 369) called
nua(0x80985a8): adding session usage
tport_tsend(0x8091138) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091138): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091138): 331 bytes of 331 to UDP/10.60.2.20:21778
tport_vsend returned 331
send 331 bytes to udp/[10.60.2.20]:21778 at 15:33:00.995924:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-1577cc39c57f511c-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=3b66ed23
To: "5399"<sip:5399@svidev06b.tst33.cvf>
Call-ID: YTMwZTgzYjI3NTRmNWUyYjI0YTcxYWE2MjI3ZjZiMjg.
CSeq: 1 INVITE
User-Agent: FreeSWITCH(mod_sofia)
Content-Length: 0
------------------------------------------------------------------------
nta: sent 100 Trying for INVITE (1)
nua(0x80985a8): event i_invite 100 Trying
nua(0x80985a8): call state changed: init -> received, received offer
soa_get_remote_sdp(static::0x80aef90, [0x437c8de8], [0x437c8de4], [(nil)]) called
nua(0x80985a8): event i_state 100 Trying
nua: nua_event: entering
nua: nua_handle_bind: entering
nua: nua_event: entering
2007-07-24 17:33:00 [NOTICE] switch_channel.c:381 switch_channel_set_name() New Chan sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [297ded8a-39fb-11dc-b7d1-7329728bd5aa]
2007-07-24 17:33:00 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [received]
2007-07-24 17:33:00 [DEBUG] sofia.c:1032 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 5 2 IN IP4 10.60.2.20
s=CounterPath X-Lite 3.0
c=IN IP4 10.60.2.20
t=0 0
m=audio 48830 RTP/AVP 100 106 0 105 8 101
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 23838 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 QCIF=1 MaxBR=1960
2007-07-24 17:33:00 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[PCMU:0:8000]
2007-07-24 17:33:00 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[PCMU:0:8000]
2007-07-24 17:33:00 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2007-07-24 17:33:00 [DEBUG] sofia_glue.c:812 sofia_glue_tech_set_codec() Set Codec sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 PCMU/8000 20 ms 160 samples
2007-07-24 17:33:00 [DEBUG] sofia_glue.c:1166 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2007-07-24 17:33:00 [DEBUG] sofia.c:1132 sofia_handle_sip_i_state() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_NEW -> CS_INIT
2007-07-24 17:33:00 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:00 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State INIT
2007-07-24 17:33:00 [DEBUG] mod_sofia.c:92 sofia_on_init() SOFIA INIT
2007-07-24 17:33:00 [DEBUG] mod_sofia.c:105 sofia_on_init() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_INIT -> CS_RING
2007-07-24 17:33:00 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:00 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State RING
2007-07-24 17:33:00 [DEBUG] mod_sofia.c:120 sofia_on_ring() SOFIA RING
2007-07-24 17:33:00 [DEBUG] switch_core_state_machine.c:56 switch_core_standard_on_ring() Standard RING sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060
2007-07-24 17:33:00 [INFO] mod_dialplan_xml.c:316 dialplan_hunt() Processing key2->5399!
2007-07-24 17:33:00 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5391$/
2007-07-24 17:33:00 [DEBUG] mod_dialplan_xml.c:118 parse_exten() Regex mismatch
2007-07-24 17:33:00 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5390$/
2007-07-24 17:33:00 [DEBUG] mod_dialplan_xml.c:118 parse_exten() Regex mismatch
2007-07-24 17:33:00 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5399$/
2007-07-24 17:33:00 [DEBUG] mod_dialplan_xml.c:372 dialplan_hunt() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_RING -> CS_EXECUTE
2007-07-24 17:33:00 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:00 [DEBUG] switch_core_state_machine.c:437 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State EXECUTE
2007-07-24 17:33:00 [DEBUG] mod_sofia.c:137 sofia_on_execute() SOFIA EXECUTE
2007-07-24 17:33:00 [DEBUG] switch_core_state_machine.c:113 switch_core_standard_on_execute() Standard EXECUTE
2007-07-24 17:33:00 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute answer()
2007-07-24 17:33:01 [DEBUG] sofia_glue.c:876 sofia_glue_activate_rtp() AUDIO RTP [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060] 10.133.92.53:16384->10.60.2.20:48830 codec: 0 ms: 20
2007-07-24 17:33:01 [DEBUG] switch_rtp.c:538 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2007-07-24 17:33:01 [DEBUG] mod_sofia.c:317 sofia_answer_channel() Local SDP sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060:
v=0
o=FreeSWITCH 1185274797 1185274798 IN IP4 10.133.92.53
s=FreeSWITCH
c=IN IP4 10.133.92.53
t=0 0
a=sendrecv
m=audio 16384 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
nua: nua_respond: entering
nua(0x80985a8): signal r_respond
nua(0x80985a8): recv r_respond
nua(0x80985a8): signal r_respond 200 OK
nua: nua_stack_set_params: entering
soa_set_params(static::0x80aef90, ...) called
soa_set_user_sdp(static::0x80aef90, (nil), 0x809914c, -1) called
soa_set_capability_sdp(static::0x80aef90, (nil), 0x809914c, -1) called
nua: nua_invite_server_respond: entering
soa_generate_answer(static::0x80aef90) called
soa_static_offer_answer_action(0x80aef90, soa_generate_answer): called
soa_static(0x80aef90, soa_generate_answer): generating local description
soa_static(0x80aef90, soa_generate_answer): upgrade with remote description
soa_static(0x80aef90, soa_generate_answer): marking rejected media
soa_sdp_mode_set_is_needed(0x437c9104, 0x80b4728, ""): called
soa_static(0x80aef90, soa_generate_answer): storing local description
soa_activate(static::0x80aef90, (nil)) called
soa_get_local_sdp(static::0x80aef90, [(nil)], [0x437c9218], [0x437c9214]) called
tport_tsend(0x8091138) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091138): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091138): 913 bytes of 913 to UDP/10.60.2.20:21778
tport_vsend returned 913
send 913 bytes to udp/[10.60.2.20]:21778 at 15:33:01.004739:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-1577cc39c57f511c-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=3b66ed23
To: "5399" <sip:5399@svidev06b.tst33.cvf>;tag=ccpc5N56HaX6p
Call-ID: YTMwZTgzYjI3NTRmNWUyYjI0YTcxYWE2MjI3ZjZiMjg.
CSeq: 1 INVITE
Contact: <sip:mod_sofia@10.133.92.53:5060>
User-Agent: FreeSWITCH(mod_sofia)
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: 100rel, precondition
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 294
v=0
o=FreeSWITCH 2496140240298768321 768834379964387825 IN IP4 10.133.92.53
s=FreeSWITCH
c=IN IP4 10.133.92.53
t=0 0
a=sendrecv
m=audio 16384 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
m=video 0 RTP/AVP 9
------------------------------------------------------------------------
nta: sent 200 OK for INVITE (1)
nua(0x80985a8): call state changed: received -> completed, sent answer
soa_get_local_sdp(static::0x80aef90, [0x437c9290], [0x437c928c], [(nil)]) called
soa_get_params(static::0x80aef90, ...) called
nua(0x80985a8): event i_state 200 OK
nua: nua_event: entering
2007-07-24 17:33:01 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [completed]
2007-07-24 17:33:01 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:01 [NOTICE] mod_dptools.c:286 answer_function() Channel [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060] has been answered
2007-07-24 17:33:01 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute sleep(1000)
tport_wakeup_pri(0x8091138): events IN
tport_recv_event(0x8091138)
tport_recv_iovec(0x8091138) msg 0x8096248 from (udp/10.133.92.53:5060) has 438 bytes, veclen = 1
recv 438 bytes from udp/[10.60.2.20]:21778 at 15:33:01.166563:
------------------------------------------------------------------------
ACK sip:mod_sofia@10.133.92.53:5060 SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-35465b78ef0dea7f-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>;tag=ccpc5N56HaX6p
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=3b66ed23
Call-ID: YTMwZTgzYjI3NTRmNWUyYjI0YTcxYWE2MjI3ZjZiMjg.
CSeq: 1 ACK
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 0
------------------------------------------------------------------------
tport_deliver(0x8091138): msg 0x8096248 (438 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received ACK sip:mod_sofia@10.133.92.53:5060 SIP/2.0 (CSeq 1)
nta: ACK (1) is going to INVITE (1)
nua: process_ack_or_cancel: entering
soa_clear_remote_sdp(static::0x80aef90) called
nua(0x80985a8): event i_ack 200 OK
nua(0x80985a8): call state changed: completed -> ready
nua(0x80985a8): event i_state 200 OK
nua(0x80985a8): event i_active 200 Call active
nua: nua_event: entering
nua: nua_event: entering
nua: nua_event: entering
2007-07-24 17:33:01 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [ready]
nta: timer set next to 4972 ms
Cant load Video codec H263
2007-07-24 17:33:02 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute bridge(openzap/1/0/0614062706)
2007-07-24 17:33:02 [ERR] switch_core_codec.c:99 switch_core_codec_init() invalid codec H263!
2007-07-24 17:33:02 [ERR] mod_openzap.c:239 tech_init() Can't load codec?
2007-07-24 17:33:02 [DEBUG] mod_openzap.c:245 tech_init() Set codec PCMA 20ms
2007-07-24 17:33:02 [NOTICE] switch_channel.c:381 switch_channel_set_name() New Chan OPENZAP/0614062706 [2a18a690-39fb-11dc-b7d1-7329728bd5aa]
2007-07-24 17:33:02 [DEBUG] mod_openzap.c:817 channel_outgoing_channel() OPENZAP/0614062706 State Change CS_NEW -> CS_INIT
2007-07-24 17:33:02 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:02 [DEBUG] zap_isdn.c:55 isdn_outgoing_call() Changing state from DOWN to DIALING
2007-07-24 17:33:02 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (OPENZAP/0614062706) State INIT
2007-07-24 17:33:02 [DEBUG] mod_openzap.c:270 channel_on_init() OPENZAP/0614062706 State Change CS_INIT -> CS_RING
2007-07-24 17:33:02 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:02 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() (OPENZAP/0614062706) State RING
2007-07-24 17:33:02 [DEBUG] switch_ivr_originate.c:48 originate_on_ring() OPENZAP/0614062706 State Change CS_RING -> CS_HOLD
2007-07-24 17:33:02 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:02 [DEBUG] switch_core_state_machine.c:545 switch_core_session_run() (OPENZAP/0614062706) State HOLD
2007-07-24 17:33:02 [DEBUG] switch_core_state_machine.c:188 switch_core_standard_on_hold() Standard HOLD
2007-07-24 17:33:02 [DEBUG] switch_ivr_originate.c:619 switch_ivr_originate() Raw Codec Activation Success L16@8000hz 1 channel 20ms
2007-07-24 17:33:02 [DEBUG] zap_isdn.c:278 state_advance() 1:1 STATE [DIALING]
2007-07-24 17:33:02 [DEBUG] zap_isdn.c:657 q931_rx_32() WRITE 32
--------------------------------------------------------------------------------
[00 01 00 00 08 02 00 01 05 04 03 80 90 a3 18 03 a9 83 81 70 0b 80 30 36 31 34 30 36 32 37 30 36]
2007-07-24 17:33:02 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 10
--------------------------------------------------------------------------------
[08 02 80 01 0d 18 03 a9 83 81]
2007-07-24 17:33:02 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 10
--------------------------------------------------------------------------------
[08 02 80 01 02 18 03 a9 83 81]
2007-07-24 17:33:02 [DEBUG] zap_isdn.c:81 zap_isdn_931_34() Yay I got an event! Type:[02] Size:[137]
nta: timer I fired, terminate 200 response
incoming_reclaim_all((nil), (nil), 0x437c9208)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
2007-07-24 17:33:08 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 5
--------------------------------------------------------------------------------
[08 02 80 01 01]
2007-07-24 17:33:08 [DEBUG] zap_isdn.c:81 zap_isdn_931_34() Yay I got an event! Type:[01] Size:[103]
2007-07-24 17:33:08 [DEBUG] zap_isdn.c:158 zap_isdn_931_34() Changing state from DIALING to PROGRESS_MEDIA
2007-07-24 17:33:08 [DEBUG] zap_isdn.c:278 state_advance() 1:1 STATE [PROGRESS_MEDIA]
2007-07-24 17:33:08 [DEBUG] mod_openzap.c:1006 on_isdn_signal() got ISDN sig [PROGRESS_MEDIA]
2007-07-24 17:33:08 [NOTICE] switch_channel.c:1087 switch_channel_perform_mark_pre_answered() Ring-Ready OPENZAP/0614062706!
2007-07-24 17:33:08 [NOTICE] mod_openzap.c:1036 on_isdn_signal() Pre-Answer OPENZAP/0614062706!
2007-07-24 17:33:08 [DEBUG] switch_channel.c:1106 switch_channel_perform_mark_pre_answered() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:08 [DEBUG] switch_ivr_originate.c:851 switch_ivr_originate() Originate Resulted in Success: [OPENZAP/0614062706]
2007-07-24 17:33:08 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:08 [DEBUG] mod_sofia.c:795 sofia_receive_message() De-activate timed RTP!
2007-07-24 17:33:08 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:08 [DEBUG] switch_ivr_bridge.c:594 switch_ivr_multi_threaded_bridge() OPENZAP/0614062706 State Change CS_HOLD -> CS_LOOPBACK
2007-07-24 17:33:08 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:08 [DEBUG] switch_core_state_machine.c:472 switch_core_session_run() (OPENZAP/0614062706) State LOOPBACK
2007-07-24 17:33:08 [DEBUG] mod_openzap.c:410 channel_on_loopback() CHANNEL LOOPBACK
2007-07-24 17:33:08 [DEBUG] switch_core_io.c:281 switch_core_session_read_frame() Engaging Read Buffer at 320 bytes
Current price: 2
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 14
--------------------------------------------------------------------------------
[08 02 80 01 7b 20 07 00 32 33 2a 02 00 00]
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:81 zap_isdn_931_34() Yay I got an event! Type:[7b] Size:[115]
Current price: 3
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 14
--------------------------------------------------------------------------------
[08 02 80 01 7b 20 07 00 32 33 2a 03 00 00]
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:81 zap_isdn_931_34() Yay I got an event! Type:[7b] Size:[115]
After StartTimer, iFrom = 02
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 5
--------------------------------------------------------------------------------
[08 02 80 01 07]
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:81 zap_isdn_931_34() Yay I got an event! Type:[07] Size:[103]
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:168 zap_isdn_931_34() Changing state from PROGRESS_MEDIA to UP
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:657 q931_rx_32() WRITE 9
--------------------------------------------------------------------------------
[00 01 02 0c 08 02 00 01 0f]
2007-07-24 17:33:10 [DEBUG] zap_isdn.c:278 state_advance() 1:1 STATE [UP]
2007-07-24 17:33:10 [DEBUG] mod_openzap.c:1006 on_isdn_signal() got ISDN sig [UP]
2007-07-24 17:33:10 [DEBUG] switch_channel.c:1209 switch_channel_perform_mark_answered() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:10 [NOTICE] mod_openzap.c:1028 on_isdn_signal() Channel [OPENZAP/0614062706] has been answered
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b> 2007-07-24 17:33:18 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 27
--------------------------------------------------------------------------------
[08 02 80 01 45 08 02 87 90 20 07 00 32 34 2a 03 00 00 20 07 00 34 38 2a 00 00 00]
2007-07-24 17:33:18 [DEBUG] zap_isdn.c:81 zap_isdn_931_34() Yay I got an event! Type:[45] Size:[134]
2007-07-24 17:33:18 [DEBUG] zap_isdn.c:153 zap_isdn_931_34() Changing state from UP to TERMINATING
2007-07-24 17:33:18 [DEBUG] zap_isdn.c:278 state_advance() 1:1 STATE [TERMINATING]
2007-07-24 17:33:18 [DEBUG] mod_openzap.c:1006 on_isdn_signal() got ISDN sig [STOP]
2007-07-24 17:33:18 [NOTICE] mod_openzap.c:1019 on_isdn_signal() Hangup OPENZAP/0614062706 [CS_LOOPBACK] [NORMAL_CLEARING]
2007-07-24 17:33:18 [DEBUG] switch_channel.c:1061 switch_channel_perform_hangup() Kill OPENZAP/0614062706 [KILL]
2007-07-24 17:33:18 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:18 [DEBUG] zap_isdn.c:657 q931_rx_32() WRITE 9
--------------------------------------------------------------------------------
[00 01 04 0e 08 02 00 01 4d]
nua: nua_bye: entering
nua(0x80985a8): signal r_bye
2007-07-24 17:33:18 [DEBUG] mod_sofia.c:801 sofia_receive_message() Re-activate timed RTP!
2007-07-24 17:33:18 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:18 [DEBUG] switch_ivr_bridge.c:189 audio_bridge_thread() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:18 [DEBUG] switch_ivr_bridge.c:192 audio_bridge_thread() BRIDGE THREAD DONE [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060]
2007-07-24 17:33:18 [NOTICE] switch_core_state_machine.c:168 switch_core_standard_on_execute() Hangup sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2007-07-24 17:33:18 [DEBUG] switch_channel.c:1061 switch_channel_perform_hangup() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [KILL]
2007-07-24 17:33:18 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:18 [DEBUG] switch_core_state_machine.c:331 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State HANGUP
2007-07-24 17:33:18 [DEBUG] mod_sofia.c:217 sofia_on_hangup() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 hanging up, cause: NORMAL_CLEARING
2007-07-24 17:33:18 [DEBUG] mod_sofia.c:235 sofia_on_hangup() Sending BYE to sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060
2007-07-24 17:33:18 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060, cause: NORMAL_CLEARING
2007-07-24 17:33:18 [DEBUG] switch_core_session.c:706 switch_core_session_thread() Session 1 (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) Locked, Waiting on external entities
nua(0x80985a8): recv r_bye
nua(0x80985a8): signal r_bye
nua: nua_stack_set_params: entering
soa_set_params(static::0x80aef90, ...) called
soa_set_params(static::0x80aef90, ...) called
soa_terminate(static::0x80aef90) called
soa_init_offer_answer(static::0x80aef90) called
nta: selecting scheme sip
tport(0x8091138): EXPENSIVE unresolved */10.60.2.20:21778
tport_tsend(0x8091138) tpn = */10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091138): not found by name */10.60.2.20:21778
tport_vsend(0x8091138): 513 bytes of 513 to */10.60.2.20:21778
tport_vsend returned 513
send 513 bytes to udp/[10.60.2.20]:21778 at 15:33:18.106023:
------------------------------------------------------------------------
BYE sip:key2@10.60.2.20:21778 SIP/2.0
Via: SIP/2.0/UDP 10.133.92.53;rport;branch=z9hG4bKc3ceg5XgDyXag
Max-Forwards: 70
From: "5399" <sip:5399@svidev06b.tst33.cvf>;tag=ccpc5N56HaX6p
To: "key2" <sip:key2@svidev06b.tst33.cvf>;tag=3b66ed23
Call-ID: YTMwZTgzYjI3NTRmNWUyYjI0YTcxYWE2MjI3ZjZiMjg.
CSeq: 86527263 BYE
User-Agent: FreeSWITCH(mod_sofia)
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: 100rel, precondition
Content-Length: 0
------------------------------------------------------------------------
nta: sent BYE (86527263) to */10.60.2.20:21778
tport_pend(0x8091138): pending 0x80b4728 for udp/10.133.92.53:5060 (already 0)
nta: timer set to 32000 ms
nta: timer shortened to 500 ms
2007-07-24 17:33:18 [DEBUG] switch_ivr_bridge.c:173 audio_bridge_thread() write: sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 Bad Frame....[160] Bubye!
2007-07-24 17:33:18 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill OPENZAP/0614062706 [BREAK]
2007-07-24 17:33:18 [DEBUG] switch_ivr_bridge.c:189 audio_bridge_thread() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:18 [DEBUG] switch_ivr_bridge.c:192 audio_bridge_thread() BRIDGE THREAD DONE [OPENZAP/0614062706]
2007-07-24 17:33:18 [DEBUG] switch_core_state_machine.c:331 switch_core_session_run() (OPENZAP/0614062706) State HANGUP
2007-07-24 17:33:18 [DEBUG] mod_openzap.c:372 channel_on_hangup() OPENZAP/0614062706 CHANNEL HANGUP
2007-07-24 17:33:18 [DEBUG] switch_core_state_machine.c:45 switch_core_standard_on_hangup() Standard HANGUP OPENZAP/0614062706, cause: NORMAL_CLEARING
2007-07-24 17:33:18 [DEBUG] switch_core_session.c:706 switch_core_session_thread() Session 2 (OPENZAP/0614062706) Locked, Waiting on external entities
2007-07-24 17:33:18 [INFO] switch_core_session.c:712 switch_core_session_thread() Session 2 (OPENZAP/0614062706) Ended
2007-07-24 17:33:18 [NOTICE] switch_core_session.c:714 switch_core_session_thread() Close Channel OPENZAP/0614062706 [CS_HANGUP]
2007-07-24 17:33:18 [INFO] switch_core_session.c:712 switch_core_session_thread() Session 1 (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) Ended
2007-07-24 17:33:18 [NOTICE] switch_core_session.c:714 switch_core_session_thread() Close Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [CS_HANGUP]
tport_wakeup_pri(0x8091138): events IN
tport_recv_event(0x8091138)
tport_recv_iovec(0x8091138) msg 0x8096248 from (udp/10.133.92.53:5060) has 383 bytes, veclen = 1
recv 383 bytes from udp/[10.60.2.20]:21778 at 15:33:18.244369:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.133.92.53;rport=5060;branch=z9hG4bKc3ceg5XgDyXag
Contact: <sip:key2@10.60.2.20:21778>
To: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=3b66ed23
From: "5399"<sip:5399@svidev06b.tst33.cvf>;tag=ccpc5N56HaX6p
Call-ID: YTMwZTgzYjI3NTRmNWUyYjI0YTcxYWE2MjI3ZjZiMjg.
CSeq: 86527263 BYE
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 0
------------------------------------------------------------------------
tport_deliver(0x8091138): msg 0x8096248 (383 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received 200 OK for BYE (86527263)
nta: 200 OK going to a transaction
nta_outgoing: RTT is 138.885 ms
tport_release(0x8091138): 0x80b4728 by 0x80b4910 with 0x8096248
nua(0x80985a8): event r_bye 200 OK
nua(0x80985a8): call state changed: terminating -> terminated
nua(0x80985a8): event i_state 200 to BYE
nua(0x80985a8): event i_terminated 200 to BYE
nua(0x80985a8): removing session usage
soa_destroy(static::0x80aef90) called
nta_leg_destroy(0x809ad18)
nua: terminated session 0x80985a8
nua: nua_event: entering
nua: nua_event: entering
nua: nua_handle_bind: entering
nua: nua_handle_destroy: entering
nua(0x80985a8): signal r_destroy
nua(0x80985a8): recv r_destroy
nua(0x80985a8): signal r_destroy
nta_leg_destroy((nil))
nua: nua_event: entering
nua(0x80985a8): event i_terminated dropped
nua(0x80985a8): freed by application
2007-07-24 17:33:18 [DEBUG] zap_isdn.c:245 zap_isdn_921_23() READ 9
--------------------------------------------------------------------------------
[08 02 80 01 5a 08 02 87 90]
nta: timer set next to 4638 ms
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b> nta: timer K fired, terminate BYE (86527263)
outgoing_reclaim_all((nil), (nil), 0x437c92d4)
nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b> tport_wakeup_pri(0x8091138): events IN
tport_recv_event(0x8091138)
tport_recv_iovec(0x8091138) msg 0x8099480 from (udp/10.133.92.53:5060) has 908 bytes, veclen = 1
recv 908 bytes from udp/[10.60.2.20]:21778 at 15:33:28.795919:
------------------------------------------------------------------------
INVITE sip:5399@svidev06b.tst33.cvf SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-da0aa64613018748-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=bf21ca52
Call-ID: MzM4MDZlMGEzMWE0ZThjYzk5MDliYWU0MWNiYmRlZmY.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 369
v=0
o=- 7 2 IN IP4 10.60.2.20
s=CounterPath X-Lite 3.0
c=IN IP4 10.60.2.20
t=0 0
m=audio 32814 RTP/AVP 100 106 0 105 8 101
a=fmtp:101 0-15
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
m=video 14096 RTP/AVP 34
a=fmtp:34 QCIF=1 MaxBR=1960
a=rtpmap:34 H263/90000
a=sendrecv
------------------------------------------------------------------------
tport_deliver(0x8091138): msg 0x8099480 (908 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received INVITE sip:5399@svidev06b.tst33.cvf SIP/2.0 (CSeq 1)
nta: INVITE (1) going to a default leg
nta: timer set to 200 ms
nua: nua_stack_process_request: entering
nua: nh_create: entering
nua: nh_create_handle: entering
nua: nua_stack_set_params: entering
soa_clone(static::0x808e7c0, 0x808e4e8, 0x80985a8) called
soa_set_params(static::0x80aee10, ...) called
soa_set_params(static::0x80aee10, ...) called
nta_leg_create(0x80987d0)
soa_init_offer_answer(static::0x80aee10) called
soa_set_remote_sdp(static::0x80aee10, (nil), 0x80b16ab, 369) called
nua(0x80985a8): adding session usage
tport_tsend(0x8091138) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091138): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091138): 331 bytes of 331 to UDP/10.60.2.20:21778
tport_vsend returned 331
send 331 bytes to udp/[10.60.2.20]:21778 at 15:33:28.797201:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-da0aa64613018748-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=bf21ca52
To: "5399"<sip:5399@svidev06b.tst33.cvf>
Call-ID: MzM4MDZlMGEzMWE0ZThjYzk5MDliYWU0MWNiYmRlZmY.
CSeq: 1 INVITE
User-Agent: FreeSWITCH(mod_sofia)
Content-Length: 0
------------------------------------------------------------------------
nta: sent 100 Trying for INVITE (1)
nua(0x80985a8): event i_invite 100 Trying
nua: nua_event: entering
nua: nua_handle_bind: entering
nua(0x80985a8): call state changed: init -> received, received offer
soa_get_remote_sdp(static::0x80aee10, [0x437c8de8], [0x437c8de4], [(nil)]) called
nua(0x80985a8): event i_state 100 Trying
2007-07-24 17:33:28 [NOTICE] switch_channel.c:381 switch_channel_set_name() New Chan sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [3a100908-39fb-11dc-b7d1-7329728bd5aa]
nua: nua_event: entering
2007-07-24 17:33:28 [DEBUG] switch_core_state_machine.c:326 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State NEW
2007-07-24 17:33:28 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [received]
2007-07-24 17:33:28 [DEBUG] sofia.c:1032 sofia_handle_sip_i_state() Remote SDP:
v=0
o=- 7 2 IN IP4 10.60.2.20
s=CounterPath X-Lite 3.0
c=IN IP4 10.60.2.20
t=0 0
m=audio 32814 RTP/AVP 100 106 0 105 8 101
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 14096 RTP/AVP 34
a=rtpmap:34 H263/90000
a=fmtp:34 QCIF=1 MaxBR=1960
2007-07-24 17:33:28 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX:100:16000]/[PCMU:0:8000]
2007-07-24 17:33:28 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [SPEEX-FEC:106:16000]/[PCMU:0:8000]
2007-07-24 17:33:28 [DEBUG] sofia_glue.c:1202 sofia_glue_negotiate_sdp() Audio Codec Compare [PCMU:0:8000]/[PCMU:0:8000]
2007-07-24 17:33:28 [DEBUG] sofia_glue.c:812 sofia_glue_tech_set_codec() Set Codec sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 PCMU/8000 20 ms 160 samples
2007-07-24 17:33:28 [DEBUG] sofia_glue.c:1166 sofia_glue_negotiate_sdp() Set 2833 dtmf payload to 101
2007-07-24 17:33:28 [DEBUG] sofia.c:1132 sofia_handle_sip_i_state() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_NEW -> CS_INIT
2007-07-24 17:33:28 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:28 [DEBUG] switch_core_state_machine.c:367 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State INIT
2007-07-24 17:33:28 [DEBUG] mod_sofia.c:92 sofia_on_init() SOFIA INIT
2007-07-24 17:33:28 [DEBUG] mod_sofia.c:105 sofia_on_init() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_INIT -> CS_RING
2007-07-24 17:33:28 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:28 [DEBUG] switch_core_state_machine.c:402 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State RING
2007-07-24 17:33:28 [DEBUG] mod_sofia.c:120 sofia_on_ring() SOFIA RING
2007-07-24 17:33:28 [DEBUG] switch_core_state_machine.c:56 switch_core_standard_on_ring() Standard RING sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060
2007-07-24 17:33:28 [INFO] mod_dialplan_xml.c:316 dialplan_hunt() Processing key2->5399!
2007-07-24 17:33:28 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5391$/
2007-07-24 17:33:28 [DEBUG] mod_dialplan_xml.c:118 parse_exten() Regex mismatch
2007-07-24 17:33:28 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5390$/
2007-07-24 17:33:28 [DEBUG] mod_dialplan_xml.c:118 parse_exten() Regex mismatch
2007-07-24 17:33:28 [DEBUG] mod_dialplan_xml.c:116 parse_exten() test conditions destination_number(5399) =~ /^5399$/
2007-07-24 17:33:28 [DEBUG] mod_dialplan_xml.c:372 dialplan_hunt() sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 State Change CS_RING -> CS_EXECUTE
2007-07-24 17:33:28 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:28 [DEBUG] switch_core_state_machine.c:437 switch_core_session_run() (sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060) State EXECUTE
nua: nua_respond: entering
nua(0x80985a8): signal r_respond
2007-07-24 17:33:28 [DEBUG] mod_sofia.c:137 sofia_on_execute() SOFIA EXECUTE
2007-07-24 17:33:28 [DEBUG] switch_core_state_machine.c:113 switch_core_standard_on_execute() Standard EXECUTE
2007-07-24 17:33:28 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute answer()
2007-07-24 17:33:28 [DEBUG] sofia_glue.c:876 sofia_glue_activate_rtp() AUDIO RTP [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060] 10.133.92.53:16386->10.60.2.20:32814 codec: 0 ms: 20
2007-07-24 17:33:28 [DEBUG] switch_rtp.c:538 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms
2007-07-24 17:33:28 [DEBUG] mod_sofia.c:317 sofia_answer_channel() Local SDP sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060:
v=0
o=FreeSWITCH 1185274822 1185274823 IN IP4 10.133.92.53
s=FreeSWITCH
c=IN IP4 10.133.92.53
t=0 0
a=sendrecv
m=audio 16386 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
2007-07-24 17:33:28 [DEBUG] switch_core_session.c:349 switch_core_session_receive_message() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
2007-07-24 17:33:28 [NOTICE] mod_dptools.c:286 answer_function() Channel [sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060] has been answered
2007-07-24 17:33:28 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute sleep(1000)
nua(0x80985a8): recv r_respond
nua(0x80985a8): signal r_respond 200 OK
nua: nua_stack_set_params: entering
soa_set_params(static::0x80aee10, ...) called
soa_set_user_sdp(static::0x80aee10, (nil), 0x80cce54, -1) called
soa_set_capability_sdp(static::0x80aee10, (nil), 0x80cce54, -1) called
nua: nua_invite_server_respond: entering
soa_generate_answer(static::0x80aee10) called
soa_static_offer_answer_action(0x80aee10, soa_generate_answer): called
soa_static(0x80aee10, soa_generate_answer): generating local description
soa_static(0x80aee10, soa_generate_answer): upgrade with remote description
soa_static(0x80aee10, soa_generate_answer): marking rejected media
soa_sdp_mode_set_is_needed(0x437c9104, 0x80ca318, ""): called
soa_static(0x80aee10, soa_generate_answer): storing local description
soa_activate(static::0x80aee10, (nil)) called
soa_get_local_sdp(static::0x80aee10, [(nil)], [0x437c9218], [0x437c9214]) called
tport_tsend(0x8091138) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091138): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091138): 913 bytes of 913 to UDP/10.60.2.20:21778
tport_vsend returned 913
send 913 bytes to udp/[10.60.2.20]:21778 at 15:33:28.805452:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-da0aa64613018748-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=bf21ca52
To: "5399" <sip:5399@svidev06b.tst33.cvf>;tag=DNF56gpaFKKSj
Call-ID: MzM4MDZlMGEzMWE0ZThjYzk5MDliYWU0MWNiYmRlZmY.
CSeq: 1 INVITE
Contact: <sip:mod_sofia@10.133.92.53:5060>
User-Agent: FreeSWITCH(mod_sofia)
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: 100rel, precondition
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 294
v=0
o=FreeSWITCH 3528640557570316341 733355037184657903 IN IP4 10.133.92.53
s=FreeSWITCH
c=IN IP4 10.133.92.53
t=0 0
a=sendrecv
m=audio 16386 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
m=video 0 RTP/AVP 9
------------------------------------------------------------------------
nta: sent 200 OK for INVITE (1)
nua(0x80985a8): call state changed: received -> completed, sent answer
soa_get_local_sdp(static::0x80aee10, [0x437c9290], [0x437c928c], [(nil)]) called
soa_get_params(static::0x80aee10, ...) called
nua(0x80985a8): event i_state 200 OK
nua: nua_event: entering
2007-07-24 17:33:28 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [completed]
tport_wakeup_pri(0x8091138): events IN
tport_recv_event(0x8091138)
tport_recv_iovec(0x8091138) msg 0x80b6e00 from (udp/10.133.92.53:5060) has 438 bytes, veclen = 1
recv 438 bytes from udp/[10.60.2.20]:21778 at 15:33:28.852511:
------------------------------------------------------------------------
ACK sip:mod_sofia@10.133.92.53:5060 SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-0e10974ec8667640-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>;tag=DNF56gpaFKKSj
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=bf21ca52
Call-ID: MzM4MDZlMGEzMWE0ZThjYzk5MDliYWU0MWNiYmRlZmY.
CSeq: 1 ACK
User-Agent: X-Lite release 1011s stamp 41150
Content-Length: 0
------------------------------------------------------------------------
tport_deliver(0x8091138): msg 0x80b6e00 (438 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received ACK sip:mod_sofia@10.133.92.53:5060 SIP/2.0 (CSeq 1)
nta: ACK (1) is going to INVITE (1)
nua: process_ack_or_cancel: entering
soa_clear_remote_sdp(static::0x80aee10) called
nua(0x80985a8): event i_ack 200 OK
nua: nua_event: entering
nua(0x80985a8): call state changed: completed -> ready
nua(0x80985a8): event i_state 200 OK
nua: nua_event: entering
nua(0x80985a8): event i_active 200 Call active
nua: nua_event: entering
2007-07-24 17:33:28 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [ready]
nta: timer set next to 4857 ms
2007-07-24 17:33:29 [NOTICE] switch_core_state_machine.c:123 switch_core_standard_on_execute() Execute bridge(openzap/1/0/0614062706)
nta: timer I fired, terminate 200 response
incoming_reclaim_all((nil), (nil), 0x437c9208)
nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
nta: timer not set
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b> tport_wakeup_pri(0x8091138): events IN
tport_recv_event(0x8091138)
tport_recv_iovec(0x8091138) msg 0x8099480 from (udp/10.133.92.53:5060) has 478 bytes, veclen = 1
recv 478 bytes from udp/[10.60.2.20]:21778 at 15:34:08.887020:
------------------------------------------------------------------------
BYE sip:mod_sofia@10.133.92.53:5060 SIP/2.0
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-d2173125191adf6d-1--d87543-
Max-Forwards: 70
Contact: <sip:key2@10.60.2.20:21778>
To: "5399"<sip:5399@svidev06b.tst33.cvf>;tag=DNF56gpaFKKSj
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=bf21ca52
Call-ID: MzM4MDZlMGEzMWE0ZThjYzk5MDliYWU0MWNiYmRlZmY.
CSeq: 2 BYE
User-Agent: X-Lite release 1011s stamp 41150
Reason: SIP;description="User Hung Up"
Content-Length: 0
------------------------------------------------------------------------
tport_deliver(0x8091138): msg 0x8099480 (478 bytes) from udp/10.60.2.20:5060/sip next=(nil)
nta: received BYE sip:mod_sofia@10.133.92.53:5060 SIP/2.0 (CSeq 2)
nta: canonizing sip:mod_sofia@10.133.92.53:5060 with contact
nta: BYE (2) going to existing leg
nua: nua_stack_process_request: entering
tport_tsend(0x8091138) tpn = UDP/10.60.2.20:21778
tport_resolve addrinfo = 10.60.2.20:21778
tport_by_addrinfo(0x8091138): not found by name UDP/10.60.2.20:21778
tport_vsend(0x8091138): 483 bytes of 483 to UDP/10.60.2.20:21778
tport_vsend returned 483
send 483 bytes to udp/[10.60.2.20]:21778 at 15:34:08.887704:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.60.2.20:21778;branch=z9hG4bK-d87543-d2173125191adf6d-1--d87543-
From: "key2"<sip:key2@svidev06b.tst33.cvf>;tag=bf21ca52
To: "5399"<sip:5399@svidev06b.tst33.cvf>;tag=DNF56gpaFKKSj
Call-ID: MzM4MDZlMGEzMWE0ZThjYzk5MDliYWU0MWNiYmRlZmY.
CSeq: 2 BYE
User-Agent: FreeSWITCH(mod_sofia)
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO
Supported: 100rel, precondition
Content-Length: 0
------------------------------------------------------------------------
nta: sent 200 OK for BYE (2)
nta: timer set to 32000 ms
nua(0x80985a8): event i_bye 200 OK
nua(0x80985a8): removing session usage
soa_destroy(static::0x80aee10) called
nta_leg_destroy(0x80987d0)
nua(0x80985a8): call state changed: init -> terminated
nua(0x80985a8): event i_state 200 Received BYE
nua(0x80985a8): event i_terminated 200 Received BYE
nua: nua_event: entering
nua: nua_event: entering
nua: nua_handle_bind: entering
nua: nua_handle_destroy: entering
nua(0x80985a8): signal r_destroy
nua: nua_event: entering
nua(0x80985a8): event i_terminated dropped
2007-07-24 17:34:08 [DEBUG] sofia.c:1028 sofia_handle_sip_i_state() Channel sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 entering state [terminated]
2007-07-24 17:34:08 [NOTICE] sofia.c:1317 sofia_handle_sip_i_state() Hangup sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2007-07-24 17:34:08 [DEBUG] switch_channel.c:1061 switch_channel_perform_hangup() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [KILL]
2007-07-24 17:34:08 [DEBUG] switch_core_session.c:647 switch_core_session_signal_state_change() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [BREAK]
nua(0x80985a8): recv r_destroy
nua(0x80985a8): signal r_destroy
nta_leg_destroy((nil))
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b>
freeswitch@svidev06b> 2007-07-24 17:34:14 [CONSOLE] switch_core.c:647 switch_core_destroy() End existing sessions
2007-07-24 17:34:14 [DEBUG] switch_core_session.c:90 switch_core_session_hupall() Kill sofia/mydomain.com/key2@svidev06b.tst33.cvf:5060 [KILL]
2007-07-24 17:34:25 [CONSOLE] switch_core.c:649 switch_core_destroy() Clean up modules.
2007-07-24 17:34:25 [CONSOLE] switch_loadable_module.c:1068 do_shutdown() mod_sndfile has no shutdown routine
2007-07-24 17:34:25 [CONSOLE] switch_loadable_module.c:1068 do_shutdown() mod_dptools has no shutdown routine
2007-07-24 17:34:25 [CONSOLE] switch_loadable_module.c:1068 do_shutdown() mod_native_file has no shutdown routine
2007-07-24 17:34:25 [CONSOLE] switch_loadable_module.c:1068 do_shutdown() mod_gsm has no shutdown routine
2007-07-24 17:34:25 [CONSOLE] switch_loadable_module.c:1068 do_shutdown() mod_commands has no shutdown routine
2007-07-24 17:34:25 [CONSOLE] switch_loadable_module.c:1054 do_shutdown() Stopping: mod_sofia
2007-07-24 17:34:25 [CRIT] switch_core_session.c:98 switch_core_session_hupall() Giving up with 1 session remaining
2007-07-24 17:34:25 [NOTICE] switch_loadable_module.c:523 switch_loadable_module_unprocess() Deleting File Format 'aiff'
2007-07-24 17:34:25 [NOTICE] switch_loadable_module.c:523 switch_loadable_module_unprocess() Deleting File Format 'au'