2007-01-03 20:08:29 [CONSOLE] switch_core.c:4135 switch_core_init_and_modload() Bringing up environment. 2007-01-03 20:08:29 [CONSOLE] switch_core.c:4136 switch_core_init_and_modload() Loading Modules. 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_console] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_event_socket] 2007-01-03 20:08:29 [DEBUG] mod_event_socket.c:981 switch_module_runtime() Socket up listening on 127.0.0.1:8021 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_portaudio] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_bridgecall] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_echo] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_dptools] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_playback] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_commands] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_dialplan_xml] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_g711] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_gsm] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_l16] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_sndfile] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_softtimer] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_cepstral] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_conference] Number of devices = 0 ---------------------------------------------- 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:102 switch_loadable_module_process() Adding Endpoint 'portaudio' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'pacall' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'pahup' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'painfo' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'paoffhook' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'padtmf' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'bridge' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'echo' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'privacy' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'transfer' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'sleep' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'strftime' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'phrase' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'eval' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'answer' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'hangup' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'log' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'info' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'set' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'ringback' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'detect_speech' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'ivr' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'presence' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'strftime' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'chat' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'playback' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'stop_record_session' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'record_session' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'record' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'speak' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'originate' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'killchan' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'reloadxml' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'load' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'transfer' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'pause' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'show' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'status' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'uuid_bridge' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'broadcast' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'hold' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'media' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'fsctl' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'help' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'version' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:135 switch_loadable_module_process() Adding Dialplan 'XML' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 20ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'PCMU' (g711 ulaw) 8000hz 60ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'PCMA' (g711 alaw) 8000hz 20ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'GSM' (gsm) 8000hz 20ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 120ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 60ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 30ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 8000hz 20ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 16000hz 20ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 22050hz 20ms 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'L16' (raw signed linear (16 bit)) 32000hz 20ms 2007-01-03 20:08:29 [INFO] mod_sndfile.c:286 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-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'aiff' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'au' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'avr' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'caf' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'htk' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'iff' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'mat' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'paf' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'pvf' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'raw' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'sd2' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'sds' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'sf' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'voc' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'w64' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'wav' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'xi' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'r8' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'r16' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'r24' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'r32' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:198 switch_loadable_module_process() Adding File Format 'gsm' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:149 switch_loadable_module_process() Adding Timer 'soft' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:213 switch_loadable_module_process() Adding Speech interface 'cepstral' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:163 switch_loadable_module_process() Adding Application 'conference' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:180 switch_loadable_module_process() Adding API Function 'conference' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:255 switch_loadable_module_process() Adding Chat interface 'conf' 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_sofia] 2007-01-03 20:08:29 [NOTICE] mod_sofia.c:5010 config_sofia() Started Profile test [sip:mod_sofia@10.3.3.104:5060] 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:102 switch_loadable_module_process() Adding Endpoint 'sofia' 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:255 switch_loadable_module_process() Adding Chat interface 'sip' 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_amr] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:347 switch_loadable_module_load_file() Successfully Loaded [mod_iax] 2007-01-03 20:08:29 [CONSOLE] switch_loadable_module.c:564 switch_loadable_module_init() open of post_load_modules.conf failed 2007-01-03 20:08:29 [CONSOLE] switch_core.c:4148 switch_core_init_and_modload() FreeSWITCH Version 1.0.@SVN_VERSION@ Started. Crash Protection [DISABLED] Max Sessions[1000] freeswitch@bankshot> 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:113 switch_loadable_module_process() Adding Codec 'AMR' (GSM-AMR) 8000hz 20ms 2007-01-03 20:08:29 [INFO] mod_iax.c:954 switch_module_runtime() IAX Ready Port 4569 2007-01-03 20:08:29 [NOTICE] switch_loadable_module.c:102 switch_loadable_module_process() Adding Endpoint 'iax' recv 756 bytes from udp/[10.3.3.8]:5060 at 02:08:33.156918: ------------------------------------------------------------------------ REGISTER sip:10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.8;branch=z9hG4bKd7ce31dd3712CFE From: "Anthony Minessale" ;tag=21504E0-BB9858DF To: CSeq: 24 REGISTER Call-ID: 63f65d7c-5d257c4e-d3321e2d@10.3.3.8 Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.4.1 Authorization: Digest username="polycom500", realm="10.3.3.104", nonce="46189e88-9b98-11db-ba24-1948af26ee9d", qop=auth, cnonce="o[K`ptrEAB^Eo]z", nc=00000001, uri="sip:10.3.3.104:5060", response="6353a09f684fc7fad9e64fba5b7a3f9d", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:08:33 [DEBUG] mod_sofia.c:3067 handle_register() Requesting Registration from: [polycom500@10.3.3.104] send 604 bytes to udp/[10.3.3.8]:5060 at 02:08:33.164380: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.3.3.8;branch=z9hG4bKd7ce31dd3712CFE From: "Anthony Minessale" ;tag=21504E0-BB9858DF To: ;tag=yUcNS11v6cecF Call-ID: 63f65d7c-5d257c4e-d3321e2d@10.3.3.8 CSeq: 24 REGISTER User-Agent: FreeSWITCH(mod_sofia) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: 100rel, precondition WWW-Authenticate: Digest realm="10.3.3.104", nonce="7a9737d2-9b98-11db-ac95-5d2175ac247c", stale="true", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 757 bytes from udp/[10.3.3.8]:5060 at 02:08:33.288281: ------------------------------------------------------------------------ REGISTER sip:10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.8;branch=z9hG4bKcd78568f547AFF90 From: "Anthony Minessale" ;tag=21504E0-BB9858DF To: CSeq: 25 REGISTER Call-ID: 63f65d7c-5d257c4e-d3321e2d@10.3.3.8 Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" User-Agent: PolycomSoundPointIP-SPIP_500-UA/1.4.1 Authorization: Digest username="polycom500", realm="10.3.3.104", nonce="7a9737d2-9b98-11db-ac95-5d2175ac247c", qop=auth, cnonce="6R`7/SlD_e\vH_K", nc=00000001, uri="sip:10.3.3.104:5060", response="2c4742543e3281fb2948170385ff335e", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:08:33 [DEBUG] mod_sofia.c:3131 handle_register() Register: From: [polycom500@10.3.3.104] Contact: ["Anthony Minessale" ] Expires: [120] send 599 bytes to udp/[10.3.3.8]:5060 at 02:08:33.298078: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.3.3.8;branch=z9hG4bKcd78568f547AFF90 From: "Anthony Minessale" ;tag=21504E0-BB9858DF To: ;tag=Z45DUvj03N4ya Call-ID: 63f65d7c-5d257c4e-d3321e2d@10.3.3.8 CSeq: 25 REGISTER Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" 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 ------------------------------------------------------------------------ freeswitch@bankshot> recv 756 bytes from udp/[10.3.3.6]:5060 at 02:08:54.659667: ------------------------------------------------------------------------ REGISTER sip:10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK9ec082efCDF0796A From: "polycom3001" ;tag=28E26F1E-5794F883 To: CSeq: 84 REGISTER Call-ID: 6fa96702-edf65b20-9b14fe35@10.3.3.6 Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.4.1 Authorization: Digest username="polycom3001", realm="10.3.3.104", nonce="63a4f280-9b98-11db-ba24-1948af26ee9d", qop=auth, cnonce="n4WG4ms`}@IF4T;", nc=00000001, uri="sip:10.3.3.104:5060", response="d5cedf444956f664de3734934d098e7f", algorithm=MD5 Max-Forwards: 70 Expires: 120 Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:08:54 [DEBUG] mod_sofia.c:3131 handle_register() Register: From: [polycom3001@10.3.3.104] Contact: ["polycom3001" ] Expires: [120] send 597 bytes to udp/[10.3.3.6]:5060 at 02:08:54.666016: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK9ec082efCDF0796A From: "polycom3001" ;tag=28E26F1E-5794F883 To: ;tag=0DZ6vQ330ytHp Call-ID: 6fa96702-edf65b20-9b14fe35@10.3.3.6 CSeq: 84 REGISTER Contact: ;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER" 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 ------------------------------------------------------------------------ freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> freeswitch@bankshot> recv 825 bytes from udp/[10.3.3.6]:5060 at 02:08:56.744708: ------------------------------------------------------------------------ INVITE sip:4#1235@10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bKbe9cc2dd22DFC08 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: CSeq: 1 INVITE Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.4.1 Supported: 100rel,replace Allow-Events: talk,hold,conference Max-Forwards: 70 Content-Type: application/sdp Content-Length: 241 v=0 o=- 1167863818 1167863818 IN IP4 10.3.3.6 s=Polycom IP Phone c=IN IP4 10.3.3.6 t=0 0 a=sendrecv m=audio 2224 RTP/AVP 18 0 8 101 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 ------------------------------------------------------------------------ send 296 bytes to udp/[10.3.3.6]:5060 at 02:08:56.746521: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bKbe9cc2dd22DFC08 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 1 INVITE User-Agent: FreeSWITCH(mod_sofia) Content-Length: 0 ------------------------------------------------------------------------ send 598 bytes to udp/[10.3.3.6]:5060 at 02:08:56.748586: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bKbe9cc2dd22DFC08 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=1prZyjm7X7g4H Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 1 INVITE User-Agent: FreeSWITCH(mod_sofia) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Supported: 100rel, precondition Proxy-Authenticate: Digest realm="10.3.3.104", nonce="88a5e486-9b98-11db-ac95-5d2175ac247c", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_i_state] status [407][Proxy Authentication Required] session: n/a recv 500 bytes from udp/[10.3.3.6]:5060 at 02:08:56.932973: ------------------------------------------------------------------------ ACK sip:4#1235@10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bKbe9cc2dd22DFC08 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=1prZyjm7X7g4H CSeq: 1 ACK Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.4.1 Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ recv 1087 bytes from udp/[10.3.3.6]:5060 at 02:08:56.982890: ------------------------------------------------------------------------ INVITE sip:4#1235@10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: CSeq: 2 INVITE Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.4.1 Supported: 100rel,replace Allow-Events: talk,hold,conference Proxy-Authorization: Digest username="polycom3001", realm="10.3.3.104", nonce="88a5e486-9b98-11db-ac95-5d2175ac247c", qop=auth, cnonce="[gO4J>8xODJ_v;x", nc=00000001, uri="sip:4#1235@10.3.3.104:5060", response="492c06538fb20a767629749b289d86b7", algorithm=MD5 Max-Forwards: 70 Content-Type: application/sdp Content-Length: 241 v=0 o=- 1167863818 1167863818 IN IP4 10.3.3.6 s=Polycom IP Phone c=IN IP4 10.3.3.6 t=0 0 a=sendrecv m=audio 2224 RTP/AVP 18 0 8 101 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 ------------------------------------------------------------------------ send 297 bytes to udp/[10.3.3.6]:5060 at 02:08:56.983600: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 2 INVITE User-Agent: FreeSWITCH(mod_sofia) Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:3131 handle_register() Register: From: [polycom3001@10.3.3.104] Contact: ["polycom3001" ] Expires: [60] 2007-01-03 20:08:56 [NOTICE] switch_channel.c:347 switch_channel_set_name() New Chan sofia/test/polycom3001@10.3.3.104 [88cb2bce-9b98-11db-ac95-5d2175ac247c] 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2538 sip_i_state() Channel sofia/test/polycom3001@10.3.3.104 entering state [received] 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2543 sip_i_state() Remote SDP: v=0 o=- 1167863818 1167863818 IN IP4 10.3.3.6 s=Polycom IP Phone c=IN IP4 10.3.3.6 t=0 0 a=sendrecv m=audio 2224 RTP/AVP 18 0 8 101 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [G729:18]/[AMR:96] 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [G729:18]/[PCMU:0] 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [G729:18]/[PCMU:0] 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [PCMU:0]/[AMR:96] 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [PCMU:0]/[PCMU:0] 2007-01-03 20:08:56 [INFO] mod_sofia.c:1375 tech_set_codec() Set Codec sofia/test/polycom3001@10.3.3.104 PCMU/8000 20 ms 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:2661 sip_i_state() sofia/test/polycom3001@10.3.3.104 State Change CS_NEW -> CS_INIT 2007-01-03 20:08:56 [DEBUG] switch_core.c:3007 switch_core_session_run() (sofia/test/polycom3001@10.3.3.104) State INIT 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:1122 sofia_on_init() SOFIA INIT 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:1133 sofia_on_init() sofia/test/polycom3001@10.3.3.104 State Change CS_INIT -> CS_RING 2007-01-03 20:08:56 [DEBUG] switch_core.c:3043 switch_core_session_run() (sofia/test/polycom3001@10.3.3.104) State RING 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:1149 sofia_on_ring() SOFIA RING 2007-01-03 20:08:56 [DEBUG] switch_core.c:2684 switch_core_standard_on_ring() Standard RING sofia/test/polycom3001@10.3.3.104 2007-01-03 20:08:56 [INFO] mod_dialplan_xml.c:218 dialplan_hunt() Processing polycom3001->4#1235! 2007-01-03 20:08:56 [DEBUG] mod_dialplan_xml.c:120 parse_exten() test conditions destination_number(4#1235) =~ /^3#(.*)$/ 2007-01-03 20:08:56 [DEBUG] mod_dialplan_xml.c:122 parse_exten() Regex mismatch 2007-01-03 20:08:56 [DEBUG] mod_dialplan_xml.c:120 parse_exten() test conditions destination_number(4#1235) =~ /^4#(.*)$/ 2007-01-03 20:08:56 [DEBUG] mod_dialplan_xml.c:337 dialplan_hunt() sofia/test/polycom3001@10.3.3.104 State Change CS_RING -> CS_EXECUTE 2007-01-03 20:08:56 [DEBUG] switch_core.c:3079 switch_core_session_run() (sofia/test/polycom3001@10.3.3.104) State EXECUTE 2007-01-03 20:08:56 [DEBUG] mod_sofia.c:1167 sofia_on_execute() SOFIA EXECUTE 2007-01-03 20:08:56 [DEBUG] switch_core.c:2735 switch_core_standard_on_execute() Standard EXECUTE 2007-01-03 20:08:56 [NOTICE] switch_core.c:2745 switch_core_standard_on_execute() Execute bridge(sofia/test/1235@nat.backendhost.com) 2007-01-03 20:08:56 [NOTICE] switch_channel.c:347 switch_channel_set_name() New Chan sofia/test/1235@nat.backendhost.com [88cc7dee-9b98-11db-ac95-5d2175ac247c] 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2121 sofia_outgoing_channel() sofia/test/1235@nat.backendhost.com State Change CS_NEW -> CS_INIT 2007-01-03 20:08:57 [DEBUG] switch_core.c:3007 switch_core_session_run() (sofia/test/1235@nat.backendhost.com) State INIT 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1122 sofia_on_init() SOFIA INIT send 1020 bytes to udp/[66.250.69.250]:5060 at 02:08:57.003582: ------------------------------------------------------------------------ INVITE sip:1235@nat.backendhost.com SIP/2.0 Via: SIP/2.0/UDP 10.3.3.104;rport;branch=z9hG4bKyg751FUvD4v1N Max-Forwards: 70 From: "polycom3001" ;tag=38aH28NerSX9r To: Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 INVITE Contact: User-Agent: FreeSWITCH(mod_sofia) 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: 320 Remote-Party-ID: "polycom3001" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 7254725581454884315 10346684618767468 IN IP4 10.3.3.104 s=FreeSWITCH c=IN IP4 10.3.3.104 t=0 0 a=sendrecv m=audio 16384 RTP/AVP 96 0 0 101 a=rtpmap:96 AMR/8000 a=fmtp:96 octet-align=0 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=ptime:20 a=ptime:60 ------------------------------------------------------------------------ 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1133 sofia_on_init() sofia/test/1235@nat.backendhost.com State Change CS_INIT -> CS_RING 2007-01-03 20:08:57 [DEBUG] switch_core.c:3043 switch_core_session_run() (sofia/test/1235@nat.backendhost.com) State RING 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1149 sofia_on_ring() SOFIA RING 2007-01-03 20:08:57 [DEBUG] switch_ivr.c:1990 audio_bridge_on_ring() CUSTOM RING 2007-01-03 20:08:57 [DEBUG] switch_ivr.c:1993 audio_bridge_on_ring() sofia/test/1235@nat.backendhost.com State Change CS_RING -> CS_HOLD 2007-01-03 20:08:57 [DEBUG] switch_core.c:3188 switch_core_session_run() (sofia/test/1235@nat.backendhost.com) State HOLD 2007-01-03 20:08:57 [DEBUG] switch_ivr.c:2004 audio_bridge_on_hold() CUSTOM HOLD 2007-01-03 20:08:57 [DEBUG] switch_ivr.c:2585 switch_ivr_originate() Raw Codec Activation Success L16@8000hz 1 channel 20ms 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_i_state] status [0][INVITE sent] session: sofia/test/1235@nat.backendhost.com 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2538 sip_i_state() Channel sofia/test/1235@nat.backendhost.com entering state [calling] recv 432 bytes from udp/[66.250.69.250]:5060 at 02:08:57.059392: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.3.3.104;branch=z9hG4bKyg751FUvD4v1N;received=69.76.83.52;rport=5060 From: "polycom3001" ;tag=38aH28NerSX9r To: Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 INVITE User-Agent: bkw.org/1.2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 ------------------------------------------------------------------------ recv 708 bytes from udp/[66.250.69.250]:5060 at 02:08:57.060776: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.3.3.104;branch=z9hG4bKyg751FUvD4v1N;received=69.76.83.52;rport=5060 From: "polycom3001" ;tag=38aH28NerSX9r To: ;tag=as78741365 Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 INVITE User-Agent: bkw.org/1.2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 218 v=0 o=root 21183 21183 IN IP4 66.250.69.250 s=session c=IN IP4 66.250.69.250 t=0 0 m=audio 27364 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - ------------------------------------------------------------------------ 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_r_invite] status [183][Session Progress] session: sofia/test/1235@nat.backendhost.com 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_i_state] status [183][Session Progress] session: sofia/test/1235@nat.backendhost.com 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2538 sip_i_state() Channel sofia/test/1235@nat.backendhost.com entering state [proceeding] 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2543 sip_i_state() Remote SDP: v=0 o=root 21183 21183 IN IP4 66.250.69.250 s=session c=IN IP4 66.250.69.250 t=0 0 m=audio 27364 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [PCMU:0]/[AMR:96] 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2177 negotiate_sdp() Codec Compare [PCMU:0]/[PCMU:0] 2007-01-03 20:08:57 [INFO] mod_sofia.c:1375 tech_set_codec() Set Codec sofia/test/1235@nat.backendhost.com PCMU/8000 20 ms 2007-01-03 20:08:57 [INFO] mod_sofia.c:1423 activate_rtp() RTP [sofia/test/1235@nat.backendhost.com] 10.3.3.104:16384->66.250.69.250:27364 codec: 0 ms: 20 2007-01-03 20:08:57 [DEBUG] switch_rtp.c:500 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1478 activate_rtp() RTP Engage VAD for sofia/test/1235@nat.backendhost.com ( in out ) 2007-01-03 20:08:57 [INFO] mod_sofia.c:1903 sofia_receive_message() Asked to send early media by sofia/test/polycom3001@10.3.3.104 2007-01-03 20:08:57 [INFO] mod_sofia.c:1423 activate_rtp() RTP [sofia/test/polycom3001@10.3.3.104] 10.3.3.104:16386->10.3.3.6:2224 codec: 0 ms: 20 2007-01-03 20:08:57 [DEBUG] switch_rtp.c:500 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1478 activate_rtp() RTP Engage VAD for sofia/test/polycom3001@10.3.3.104 ( in out ) 2007-01-03 20:08:57 [INFO] mod_sofia.c:1914 sofia_receive_message() Ring SDP: v=0 o=FreeSWITCH 163861167876537080521 163861167876537080521 IN IP4 10.3.3.104 s=FreeSWITCH c=IN IP4 10.3.3.104 t=0 0 a=sendrecv m=audio 16386 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 send 852 bytes to udp/[10.3.3.6]:5060 at 02:08:57.082462: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 2 INVITE Contact: RSeq: 1102472677 User-Agent: FreeSWITCH(mod_sofia) Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, PRACK, MESSAGE, SUBSCRIBE, NOTIFY, REFER, UPDATE, REGISTER, INFO Require: 100rel Supported: 100rel, precondition Content-Type: application/sdp Content-Disposition: session Content-Length: 246 v=0 o=FreeSWITCH 8160815585158702625 1557586077937192341 IN IP4 10.3.3.104 s=FreeSWITCH c=IN IP4 10.3.3.104 t=0 0 a=sendrecv m=audio 16386 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_i_state] status [183][Session Progress] session: sofia/test/polycom3001@10.3.3.104 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:2538 sip_i_state() Channel sofia/test/polycom3001@10.3.3.104 entering state [early] 2007-01-03 20:08:57 [NOTICE] switch_ivr.c:2788 switch_ivr_originate() Pre-Answer sofia/test/polycom3001@10.3.3.104! 2007-01-03 20:08:57 [DEBUG] switch_ivr.c:2806 switch_ivr_originate() Originate Resulted in Success: [sofia/test/1235@nat.backendhost.com] 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1879 sofia_receive_message() De-activate timed RTP! 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1879 sofia_receive_message() De-activate timed RTP! 2007-01-03 20:08:57 [DEBUG] switch_ivr.c:3301 switch_ivr_multi_threaded_bridge() sofia/test/1235@nat.backendhost.com State Change CS_HOLD -> CS_LOOPBACK 2007-01-03 20:08:57 [WARNING] switch_rtp.c:886 rtp_common_read() Auto Changing port from 66.250.69.250:27364 to 10.200.68.6:27364 2007-01-03 20:08:57 [DEBUG] switch_core.c:3115 switch_core_session_run() (sofia/test/1235@nat.backendhost.com) State LOOPBACK 2007-01-03 20:08:57 [DEBUG] mod_sofia.c:1298 sofia_on_loopback() SOFIA LOOPBACK recv 698 bytes from udp/[10.3.3.6]:5060 at 02:08:57.331189: ------------------------------------------------------------------------ PRACK sip:mod_sofia@10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bKb83edad140B6AB1C From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD CSeq: 3 PRACK Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 Contact: User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.4.1 RAck: 1102472677 2 INVITE Proxy-Authorization: Digest username="polycom3001", realm="10.3.3.104", nonce="88a5e486-9b98-11db-ac95-5d2175ac247c", qop=auth, cnonce="[gO4J>8xODJ_v;x", nc=00000001, uri="sip:4#1235@10.3.3.104:5060", response="492c06538fb20a767629749b289d86b7", algorithm=MD5 Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ send 275 bytes to udp/[10.3.3.6]:5060 at 02:08:57.331573: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bKb83edad140B6AB1C From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 3 PRACK Content-Length: 0 ------------------------------------------------------------------------ recv 619 bytes from udp/[10.3.3.6]:5060 at 02:09:00.604265: ------------------------------------------------------------------------ CANCEL sip:4#1235@10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD CSeq: 2 CANCEL Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 Contact: Proxy-Authorization: Digest username="polycom3001", realm="10.3.3.104", nonce="88a5e486-9b98-11db-ac95-5d2175ac247c", qop=auth, cnonce="[gO4J>8xODJ_v;x", nc=00000001, uri="sip:4#1235@10.3.3.104:5060", response="106bbee58079176c354bd0ce88855139", algorithm=MD5 Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ send 276 bytes to udp/[10.3.3.6]:5060 at 02:09:00.604617: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 2 CANCEL Content-Length: 0 ------------------------------------------------------------------------ send 468 bytes to udp/[10.3.3.6]:5060 at 02:09:00.604834: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 CSeq: 2 INVITE 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 ------------------------------------------------------------------------ 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_i_state] status [487][Request Terminated] session: sofia/test/polycom3001@10.3.3.104 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:2538 sip_i_state() Channel sofia/test/polycom3001@10.3.3.104 entering state [terminated] 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:832 terminate_session() Term called from line: 2810 2007-01-03 20:09:00 [NOTICE] mod_sofia.c:842 terminate_session() Hangup sofia/test/polycom3001@10.3.3.104 [CS_EXECUTE] [ORIGINATOR_CANCEL] 2007-01-03 20:09:00 [INFO] switch_channel.c:969 switch_channel_perform_hangup() Kill sofia/test/polycom3001@10.3.3.104 [1] 2007-01-03 20:09:00 [DEBUG] switch_ivr.c:1928 audio_bridge_thread() write: sofia/test/polycom3001@10.3.3.104 Bad Frame....[160] Bubye! 2007-01-03 20:09:00 [INFO] switch_ivr.c:1943 audio_bridge_thread() Kill sofia/test/polycom3001@10.3.3.104 [3] 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:1885 sofia_receive_message() Re-activate timed RTP! 2007-01-03 20:09:00 [DEBUG] switch_ivr.c:1950 audio_bridge_thread() BRIDGE THREAD DONE [sofia/test/1235@nat.backendhost.com] 2007-01-03 20:09:00 [INFO] switch_ivr.c:1943 audio_bridge_thread() Kill sofia/test/1235@nat.backendhost.com [3] 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:1885 sofia_receive_message() Re-activate timed RTP! 2007-01-03 20:09:00 [DEBUG] switch_ivr.c:1950 audio_bridge_thread() BRIDGE THREAD DONE [sofia/test/polycom3001@10.3.3.104] 2007-01-03 20:09:00 [NOTICE] switch_ivr.c:1976 audio_bridge_on_loopback() Hangup sofia/test/1235@nat.backendhost.com [CS_LOOPBACK] [NORMAL_CLEARING] 2007-01-03 20:09:00 [INFO] switch_channel.c:969 switch_channel_perform_hangup() Kill sofia/test/1235@nat.backendhost.com [1] 2007-01-03 20:09:00 [DEBUG] switch_core.c:2970 switch_core_session_run() (sofia/test/1235@nat.backendhost.com) State HANGUP 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:1247 sofia_on_hangup() Channel sofia/test/1235@nat.backendhost.com hanging up, cause: NORMAL_CLEARING 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:1270 sofia_on_hangup() Sending CANCEL to sofia/test/1235@nat.backendhost.com send 321 bytes to udp/[66.250.69.250]:5060 at 02:09:00.623464: ------------------------------------------------------------------------ CANCEL sip:1235@nat.backendhost.com SIP/2.0 Via: SIP/2.0/UDP 10.3.3.104;rport;branch=z9hG4bKyg751FUvD4v1N Max-Forwards: 70 From: "polycom3001" ;tag=38aH28NerSX9r To: Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 CANCEL Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:09:00 [DEBUG] switch_core.c:2674 switch_core_standard_on_hangup() Standard HANGUP sofia/test/1235@nat.backendhost.com, cause: NORMAL_CLEARING 2007-01-03 20:09:00 [DEBUG] switch_core.c:3413 switch_core_session_thread() Session 2 (sofia/test/1235@nat.backendhost.com) Locked, Waiting on external entities 2007-01-03 20:09:00 [DEBUG] switch_core.c:2970 switch_core_session_run() (sofia/test/polycom3001@10.3.3.104) State HANGUP 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:1247 sofia_on_hangup() Channel sofia/test/polycom3001@10.3.3.104 hanging up, cause: ORIGINATOR_CANCEL 2007-01-03 20:09:00 [DEBUG] switch_core.c:2674 switch_core_standard_on_hangup() Standard HANGUP sofia/test/polycom3001@10.3.3.104, cause: ORIGINATOR_CANCEL 2007-01-03 20:09:00 [DEBUG] switch_core.c:3413 switch_core_session_thread() Session 1 (sofia/test/polycom3001@10.3.3.104) Locked, Waiting on external entities 2007-01-03 20:09:00 [INFO] switch_core.c:3418 switch_core_session_thread() Session 1 (sofia/test/polycom3001@10.3.3.104) Ended 2007-01-03 20:09:00 [NOTICE] switch_core.c:3294 switch_core_session_destroy() Close Channel sofia/test/polycom3001@10.3.3.104 2007-01-03 20:09:00 [INFO] switch_core.c:3418 switch_core_session_thread() Session 2 (sofia/test/1235@nat.backendhost.com) Ended 2007-01-03 20:09:00 [NOTICE] switch_core.c:3294 switch_core_session_destroy() Close Channel sofia/test/1235@nat.backendhost.com recv 459 bytes from udp/[66.250.69.250]:5060 at 02:09:00.695659: ------------------------------------------------------------------------ SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 10.3.3.104;branch=z9hG4bKyg751FUvD4v1N;received=69.76.83.52;rport=5060 From: "polycom3001" ;tag=38aH28NerSX9r To: ;tag=as78741365 Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 INVITE User-Agent: bkw.org/1.2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 ------------------------------------------------------------------------ send 330 bytes to udp/[66.250.69.250]:5060 at 02:09:00.696087: ------------------------------------------------------------------------ ACK sip:1235@nat.backendhost.com SIP/2.0 Via: SIP/2.0/UDP 10.3.3.104;rport;branch=z9hG4bKyg751FUvD4v1N Max-Forwards: 70 From: "polycom3001" ;tag=38aH28NerSX9r To: ;tag=as78741365 Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 443 bytes from udp/[66.250.69.250]:5060 at 02:09:00.696308: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.3.3.104;branch=z9hG4bKyg751FUvD4v1N;received=69.76.83.52;rport=5060 From: "polycom3001" ;tag=38aH28NerSX9r To: ;tag=as78741365 Call-ID: 602b21d9-163b-122a-93a2-ededfbb29950 CSeq: 77819932 CANCEL User-Agent: bkw.org/1.2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 ------------------------------------------------------------------------ 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_r_invite] status [487][Request Terminated] session: n/a 2007-01-03 20:09:00 [DEBUG] mod_sofia.c:4405 event_callback() event [nua_i_state] status [487][Request Terminated] session: n/a recv 504 bytes from udp/[10.3.3.6]:5060 at 02:09:00.772889: ------------------------------------------------------------------------ ACK sip:mod_sofia@10.3.3.104:5060 SIP/2.0 Via: SIP/2.0/UDP 10.3.3.6;branch=z9hG4bK25adaf55BA326140 From: "polycom3001" ;tag=9F0327E7-C028F6E4 To: ;tag=2ZHr0D5aUg7pD CSeq: 2 ACK Call-ID: 8912afab-9885f759-f6720686@10.3.3.6 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_300-UA/1.4.1 Max-Forwards: 70 Content-Length: 0 ------------------------------------------------------------------------ freeswitch@bankshot> 2007-01-03 20:09:02 [CONSOLE] switch_console.c:108 switch_console_process() Bye! 2007-01-03 20:09:02 [CONSOLE] switch_core.c:4210 switch_core_destroy() End existing sessions 2007-01-03 20:09:02 [CONSOLE] switch_core.c:4212 switch_core_destroy() Clean up modules. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:617 switch_loadable_module_shutdown() Stopping: mod_iax 2007-01-03 20:09:02 [DEBUG] switch_loadable_module.c:78 switch_loadable_module_exec() Thread ended for mod_iax 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:623 switch_loadable_module_shutdown() mod_iax shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_sndfile has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_dptools has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_gsm has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_playback has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_bridgecall has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:617 switch_loadable_module_shutdown() Stopping: mod_event_socket 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:623 switch_loadable_module_shutdown() mod_event_socket shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_commands has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:617 switch_loadable_module_shutdown() Stopping: mod_sofia 2007-01-03 20:09:02 [NOTICE] mod_event_socket.c:1006 switch_module_runtime() Shutting Down 2007-01-03 20:09:02 [DEBUG] switch_loadable_module.c:78 switch_loadable_module_exec() Thread ended for mod_event_socket 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:623 switch_loadable_module_shutdown() mod_sofia shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_l16 has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_console has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_dialplan_xml has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:617 switch_loadable_module_shutdown() Stopping: mod_portaudio 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:623 switch_loadable_module_shutdown() mod_portaudio shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:617 switch_loadable_module_shutdown() Stopping: mod_conference 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:623 switch_loadable_module_shutdown() mod_conference shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:617 switch_loadable_module_shutdown() Stopping: mod_softtimer 2007-01-03 20:09:02 [DEBUG] switch_loadable_module.c:78 switch_loadable_module_exec() Thread ended for mod_softtimer 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:623 switch_loadable_module_shutdown() mod_softtimer shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_cepstral has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_echo has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_g711 has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_loadable_module.c:626 switch_loadable_module_shutdown() mod_amr has no shutdown routine 2007-01-03 20:09:02 [CONSOLE] switch_core.c:4215 switch_core_destroy() Closing Event Engine. 2007-01-03 20:09:02 [CONSOLE] switch_core.c:4220 switch_core_destroy() Waiting for unfinished SQL transactions 2007-01-03 20:09:02 [NOTICE] switch_core.c:3647 switch_core_sql_thread() SQL thread ending 2007-01-03 20:09:02 [CONSOLE] switch_core.c:4230 switch_core_destroy() Finalizing Shutdown. 2007-01-03 20:09:02 [CONSOLE] switch_log.c:161 log_thread() Logger Ended.