Parsing /dip/etc/dip.conf Parsing /dip/etc/extconfig.conf  == Binding iaxusers to mysql/dipdb/iax  == Binding iaxpeers to mysql/dipdb/iax  == Binding sipusers to mysql/dipdb/sip  == Binding sippeers to mysql/dipdb/sip  == Binding queues to mysql/dipdb/queue  == Binding queue_members to mysql/dipdb/queue_member_table DIP - Dialtech IP-PBX, Copyright (C) 1999 - 2005 Dialtech Telecom. Parsing /dip/etc/queue_mysql.conf Connecting with mysql queue_mysql: got hname of 192.168.0.200 queue_mysql: got port of 3306 queue_mysql: got sock file of /tmp/mysql.sock queue_mysql: got user of root queue_mysql: got dbname of dipdb queue_mysql: got password of strong  -- Remote UNIX connection Successfully connected to MySQL database. Inserindo: 1152043171|NONE|NONE|NONE|QUEUESTART| Argumentos OK... Dados[3] antes = NONE AGT = NONE Dados [0] = 1152043171 [1] = NONE [2] = NONE [3] = NONE [4] = QUEUESTART [5] = (null) [6] = (null) [7] = (null) [8] = (null) [9] = (null) queue_mysql: inserting a QUEUE record. DIP Event Logger Started /dip/var/log/event_log Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/dnsmgr.conf Asterisk Dynamic Loader loading preload modules: Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/modules.conf  == Manager registered action Ping  == Manager registered action Events  == Manager registered action Logoff  == Manager registered action Hangup  == Manager registered action Status  == Manager registered action Setvar  == Manager registered action Getvar  == Manager registered action Redirect  == Manager registered action Originate  == Manager registered action Command  == Manager registered action ExtensionState  == Manager registered action AbsoluteTimeout  == Manager registered action MailboxStatus  == Manager registered action MailboxCount  == Manager registered action ListCommands Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/manager.conf DIP Management interface listening on port 5038 Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/cdr.conf Jul 4 16:59:31 NOTICE[1729]: cdr.c:1166 do_reload: CDR simple logging enabled. Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/rtp.conf  == RTP Allocating from port range 10000 -> 20000 DIP PBX Core Initializing Registering builtin applications:  [AbsoluteTimeout]  == Registered application 'AbsoluteTimeout'  [Answer]  == Registered application 'Answer'  [BackGround]  == Registered application 'BackGround'  [Busy]  == Registered application 'Busy'  [Congestion]  == Registered application 'Congestion'  [DigitTimeout]  == Registered application 'DigitTimeout'  [Goto]  == Registered application 'Goto'  [GotoIf]  == Registered application 'GotoIf'  [GotoIfTime]  == Registered application 'GotoIfTime'  [ExecIfTime]  == Registered application 'ExecIfTime'  [Hangup]  == Registered application 'Hangup'  [NoOp]  == Registered application 'NoOp'  [Progress]  == Registered application 'Progress'  [ResetCDR]  == Registered application 'ResetCDR'  [ResponseTimeout]  == Registered application 'ResponseTimeout'  [Ringing]  == Registered application 'Ringing'  [SayNumber]  == Registered application 'SayNumber'  [SayDigits]  == Registered application 'SayDigits'  [SayAlpha]  == Registered application 'SayAlpha'  [SayPhonetic]  == Registered application 'SayPhonetic'  [SetAccount]  == Registered application 'SetAccount'  [SetAMAFlags]  == Registered application 'SetAMAFlags'  [SetGlobalVar]  == Registered application 'SetGlobalVar'  [SetLanguage]  == Registered application 'SetLanguage'  [Set]  == Registered application 'Set'  [SetVar]  == Registered application 'SetVar'  [ImportVar]  == Registered application 'ImportVar'  [Wait]  == Registered application 'Wait'  [WaitExten]  == Registered application 'WaitExten' Asterisk Dynamic Loader Starting: Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/modules.conf  [res_noise.so] => (White Noise Generator Application)  == Registered application 'WhiteNoise'  [skipping res_config_odbc.so]  [res_adsi.so] => (ADSI Resource) Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/adsi.conf  [res_radlib.so] => (Radius Interface - Client Routines)  == Radius Interface - Client Routines loaded.  [res_mixmonitor.so] => (Mixed Audio Monitoring Application)  == Registered application 'MixMonitor'  == Registered application 'StopMixMonitor'  [res_monitor.so] => (Call Monitoring Resource)  == Registered application 'Monitor'  == Registered application 'StopMonitor'  == Registered application 'ChangeMonitor'  == Manager registered action Monitor  == Manager registered action StopMonitor  == Manager registered action ChangeMonitor  [res_crypto.so] => (Cryptographic Digital Signatures)  -- Loaded PUBLIC key 'freeworlddialup' Jul 4 16:59:31 DEBUG[1729]: res_crypto.c:257 try_load_key: Key 'freeworlddialup' loaded OK  -- Loaded PUBLIC key 'iaxtel' Jul 4 16:59:31 DEBUG[1729]: res_crypto.c:257 try_load_key: Key 'iaxtel' loaded OK  [skipping res_odbc.so]  [res_features.so] => (Call Features Resource) Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/features.conf  == Remapping feature Blind Transfer (blindxfer) to sequence '#1'  == Remapping feature Disconnect Call (disconnect) to sequence '*0'  == Remapping feature One Touch Monitor (automon) to sequence '*1'  == Remapping feature Attended Transfer (atxfer) to sequence '*2' Jul 4 16:59:31 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'parkedcalls' Jul 4 16:59:31 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '700' priority 1 to parkedcalls  == Registered application 'ParkedCall'  == Registered application 'Park'  == Manager registered action ParkedCalls  [res_indications.so] => (Indications Configuration) Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/indications.conf  -- Registered indication country 'at'  -- Registered indication country 'au'  -- Registered indication country 'br'  -- Registered indication country 'be'  -- Registered indication country 'ch'  -- Registered indication country 'cl'  -- Registered indication country 'cn'  -- Registered indication country 'cz'  -- Registered indication country 'de'  -- Registered indication country 'dk'  -- Registered indication country 'ee'  -- Registered indication country 'es'  -- Registered indication country 'fi'  -- Registered indication country 'fr'  -- Registered indication country 'gr'  -- Registered indication country 'hu'  -- Registered indication country 'it'  -- Registered indication country 'lt'  -- Registered indication country 'mx'  -- Registered indication country 'nl'  -- Registered indication country 'no'  -- Registered indication country 'nz'  -- Registered indication country 'pl'  -- Registered indication country 'pt'  -- Registered indication country 'ru'  -- Registered indication country 'se'  -- Registered indication country 'sg'  -- Registered indication country 'uk'  -- Registered indication country 'us'  -- Registered indication country 'us-o'  -- Registered indication country 'tw'  -- Registered indication country 'za'  -- Setting default indication country to 'us'  == Registered application 'PlayTones'  == Registered application 'StopPlayTones'  [res_config_mysql.so] => (MySQL RealTime Configuration Driver) Jul 4 16:59:31 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/res_mysql.conf Jul 4 16:59:31 DEBUG[1729]: res_config_mysql.c:560 parse_config: MySQL RealTime Host: 192.168.0.200 Jul 4 16:59:31 DEBUG[1729]: res_config_mysql.c:561 parse_config: MySQL RealTime Port: 3306 Jul 4 16:59:31 DEBUG[1729]: res_config_mysql.c:565 parse_config: MySQL RealTime User: root Jul 4 16:59:31 DEBUG[1729]: res_config_mysql.c:566 parse_config: MySQL RealTime Password: strong Jul 4 16:59:33 DEBUG[1737]: manager.c:1253 process_message: Manager received command 'Login' Jul 4 16:59:33 DEBUG[1737]: config.c:595 config_text_file_load: Parsing /dip/etc/manager.conf  == Manager 'ipserver' logged on from 192.168.0.200 Jul 4 16:59:41 DEBUG[1729]: res_config_mysql.c:610 mysql_reconnect: MySQL RealTime: Successfully connected to database. Jul 4 16:59:41 NOTICE[1729]: config.c:863 ast_config_engine_register: Registered Config Engine mysql MySQL RealTime driver loaded.  [res_musiconhold.so] => (Music On Hold Resource)  == Registered application 'MusicOnHold'  == Registered application 'WaitMusicOnHold'  == Registered application 'SetMusicOnHold'  == Registered application 'StartMusicOnHold'  == Registered application 'StopMusicOnHold' Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/musiconhold.conf  [res_agi.so] => (Asterisk Gateway Interface (AGI))  == Registered application 'DeadAGI'  == Registered application 'EAGI'  == Registered application 'AGI' Jul 4 16:59:41 WARNING[1738]: res_musiconhold.c:336 spawn_mp3: /dip12/var/lib/mohmp3 is not a valid directory  [skipping chan_skinny.so]  [skipping chan_oss.so]  [chan_zap.so]Jul 4 16:59:41 WARNING[1738]: res_musiconhold.c:488 monmp3thread: Unable to spawn mp3player => (Zapata Telephony w/PRI) Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/zapata.conf Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 1, with 0 conference users  -- Registered channel 1, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 2, with 0 conference users  -- Registered channel 2, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 3, with 0 conference users  -- Registered channel 3, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 4, with 0 conference users  -- Registered channel 4, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 5, with 0 conference users  -- Registered channel 5, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 6, with 0 conference users  -- Registered channel 6, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 7, with 0 conference users  -- Registered channel 7, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 8, with 0 conference users  -- Registered channel 8, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 9, with 0 conference users  -- Registered channel 9, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 10, with 0 conference users  -- Registered channel 10, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 11, with 0 conference users  -- Registered channel 11, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 12, with 0 conference users  -- Registered channel 12, FXO Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 13, with 0 conference users  -- Registered channel 13, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 14, with 0 conference users  -- Registered channel 14, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 15, with 0 conference users  -- Registered channel 15, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 16, with 0 conference users  -- Registered channel 16, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 17, with 0 conference users  -- Registered channel 17, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 18, with 0 conference users  -- Registered channel 18, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 19, with 0 conference users  -- Registered channel 19, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 20, with 0 conference users  -- Registered channel 20, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 21, with 0 conference users  -- Registered channel 21, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 22, with 0 conference users  -- Registered channel 22, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 23, with 0 conference users  -- Registered channel 23, FXS Kewlstart signalling Jul 4 16:59:41 DEBUG[1729]: chan_zap.c:1371 update_conf: Updated conferencing on 24, with 0 conference users  -- Registered channel 24, FXS Kewlstart signalling  -- Automatically generated pseudo channel Jul 4 16:59:41 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'Zap' (Zapata Telephony Driver w/PRI)  == Registered channel type 'Zap' (Zapata Telephony Driver w/PRI)  == Manager registered action ZapTransfer  == Manager registered action ZapHangup  == Manager registered action ZapDialOffhook  == Manager registered action ZapDNDon  == Manager registered action ZapDNDoff  == Manager registered action ZapShowChannels  [skipping chan_mgcp.so]  [chan_phone.so] => (Linux Telephony API Support) Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/phone.conf Jul 4 16:59:41 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'Phone' (Standard Linux Telephony API Driver)  == Registered channel type 'Phone' (Standard Linux Telephony API Driver)  [chan_iax2.so] => (Inter Asterisk eXchange (Ver 2))  == Registered custom function IAXPEER  == Registered application 'IAX2Provision'  == Manager registered action IAXpeers  == Manager registered action IAXnetstats Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/iax.conf Jul 4 16:59:41 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'IAX2' (Inter Asterisk eXchange Driver (Ver 2))  == Registered channel type 'IAX2' (Inter Asterisk eXchange Driver (Ver 2))  == Using TOS bits 16  == Binding IAX2 to default address 0.0.0.0:4569  == IAX Ready and Listening Jul 4 16:59:41 WARNING[1729]: chan_iax2.c:1254 try_firmware: Firmware file '/dip/var/lib/firmware/iax/iaxy.bin' fails checksum Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/iaxprov.conf  -- Loaded provisioning template 'default'  -- Loaded provisioning template '*'  [chan_agent.so] => (Agent Proxy Channel) Jul 4 16:59:41 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'Agent' (Call Agent Proxy Channel)  == Registered channel type 'Agent' (Call Agent Proxy Channel)  == Registered application 'AgentLogin'  == Registered application 'AgentCallbackLogin'  == Registered application 'AgentMonitorOutgoing'  == Registered application 'AgentCallbackLogoff'  == Manager registered action Agent  == Manager registered action Agents  == Manager registered action AgentLogoff  == Manager registered action AgentCallbackLogin Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/agents.conf  [skipping chan_alsa.so]  [chan_features.so] => (Feature Proxy Channel) Jul 4 16:59:41 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'Feature' (Feature Proxy Channel Driver)  == Registered channel type 'Feature' (Feature Proxy Channel Driver)  [skipping chan_unicall.so]  [chan_sip.so] => (Session Initiation Protocol (SIP)) Jul 4 16:59:41 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/sip.conf Jul 4 16:59:41 DEBUG[1729]: acl.c:199 ast_append_ha: 192.168.0.1/255.255.255.0/255.255.255.0 appended to acl for peer Jul 4 16:59:41 DEBUG[1729]: chan_sip.c:12316 reload_config: Setting User Agent Name to Dialtech IP PBX  -- Remote UNIX connection disconnected  == SIP Listening on 0.0.0.0:5060  == Using TOS bits 16 Jul 4 16:59:46 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/sip_notify.conf Jul 4 16:59:46 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'SIP' (Session Initiation Protocol (SIP))  == Registered channel type 'SIP' (Session Initiation Protocol (SIP))  == Registered application 'SIPDtmfMode'  == Registered application 'SIPAddHeader'  == Registered application 'SIPGetHeader'  == Registered custom function SIP_HEADER  == Registered custom function SIPPEER  == Registered custom function SIPCHANINFO  == Registered custom function CHECKSIPDOMAIN  == Manager registered action SIPpeers  == Manager registered action SIPshowpeer  [chan_local.so] => (Local Proxy Channel) Jul 4 16:59:46 DEBUG[1729]: channel.c:345 ast_channel_register: Registered handler for 'Local' (Local Proxy Channel Driver)  == Registered channel type 'Local' (Local Proxy Channel Driver)  [pbx_realtime.so] => (Realtime Switch)  [pbx_ael.so] => (Asterisk Extension Language Compiler) Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'incoming' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension 's' priority 1 to incoming Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 's' priority 2 to incoming Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 's' priority 3 to incoming Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'ramais'  -- Including context 'commands' in context 'ramais'  -- Including context 'from-sip' in context 'ramais'  -- Including context 'from-iax' in context 'ramais'  -- Including context 'saida' in context 'ramais' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_2X' priority 1 to ramais Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_2X' priority 2 to ramais Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'from-sip'  -- Including context 'commands' in context 'from-sip'  -- Including context 'ramais' in context 'from-sip'  -- Including context 'saida' in context 'from-sip' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '3005' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3005' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '3002' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3002' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3002' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '3003' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3003' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3003' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '7777' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7777' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7777' priority 4 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7777' priority 5 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7777' priority 7 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7777' priority 8 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4796 ast_add_extension2: Added extension '7777' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4796 ast_add_extension2: Added extension '7777' priority 6 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '3040' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3040' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3040' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_700.' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_700.' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '_*55XXXX' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*55XXXX' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '6001' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6001' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6001' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6001' priority 4 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '6000' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 4 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 5 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 6 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 7 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 8 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '6000' priority 9 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension 'sw-8-1' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-8-1' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-8-1' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension 'sw-2-3' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-2-3' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-2-3' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_sw-2-.' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_sw-2-.' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-8-1' priority 4 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension 'sw-8-2' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-8-2' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 'sw-8-2' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_sw-8-.' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_sw-8-.' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_sw-8-.' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '7001' priority 1 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7001' priority 2 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '7001' priority 3 to from-sip Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'ramal-roberto' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension 's' priority 1 to ramal-roberto Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension 's' priority 2 to ramal-roberto Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'from-iax' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '3006' priority 1 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3006' priority 2 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '3007' priority 1 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3007' priority 2 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '3008' priority 1 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3008' priority 2 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '3009' priority 1 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3009' priority 2 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '3010' priority 1 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '3010' priority 2 to from-iax Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'calls'  -- Including context 'commands' in context 'calls'  -- Including context 'saida' in context 'calls' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_30XX' priority 1 to calls Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_30XX' priority 2 to calls Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_4XXX' priority 1 to calls Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_4XXX' priority 2 to calls Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'commands' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_*100XXXXXXXXX' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*100XXXXXXXXX' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*100XXXXXXXXX' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_*101XXXXX' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*101XXXXX' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*101XXXXX' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_*102XXXXX' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*102XXXXX' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*102XXXXX' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_*103XXXXX' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*103XXXXX' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_*103XXXXX' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*80' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*80' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*80' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*80' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*80' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*81' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*81' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*81' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*81' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*81' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*82' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*82' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*82' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*82' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*82' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*82' priority 6 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*83' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*83' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*83' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*83' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*83' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*84' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*84' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*84' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*84' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*84' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*41' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*41' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*41' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*41' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*41' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*42' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*42' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*42' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*42' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*42' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*42' priority 6 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*43' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*43' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*43' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*43' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*43' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '*44' priority 1 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*44' priority 2 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*44' priority 3 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*44' priority 4 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*44' priority 5 to commands Jul 4 16:59:46 DEBUG[1729]: pbx.c:3665 ast_context_create: Registered context 'saida' Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '*57' priority 1 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '*57' priority 2 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_0ZXXXXXXX' priority 1 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_0ZXXXXXXX' priority 2 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_0ZXXXXXXX' priority 3 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_0ZXXXXXXX' priority 4 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '_00ZXXXXXXXXX' priority 1 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_00ZXXXXXXXXX' priority 2 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_00ZXXXXXXXXX' priority 3 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_00ZXXXXXXXXX' priority 4 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4844 ast_add_extension2: Added extension '_XX' priority 1 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_XX' priority 2 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '_3XXX' priority 1 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_3XXX' priority 2 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4829 ast_add_extension2: Added extension '_66XXX' priority 1 to saida Jul 4 16:59:46 DEBUG[1729]: pbx.c:4810 ast_add_extension2: Added extension '_66XXX' priority 2 to saida  [pbx_functions.so] => (Builtin dialplan functions)  == Registered custom function MD5  == Registered custom function CHECK_MD5  == Registered custom function MATH  == Registered custom function GROUP_COUNT  == Registered custom function GROUP_MATCH_COUNT  == Registered custom function GROUP  == Registered custom function GROUP_LIST  == Registered custom function FIELDQTY  == Registered custom function REGEX  == Registered custom function LEN  == Registered custom function STRFTIME  == Registered custom function EVAL  == Registered custom function CDR  == Registered custom function ISNULL  == Registered custom function SET  == Registered custom function EXISTS  == Registered custom function IF  == Registered custom function IFTIME  == Registered custom function ENV  == Registered custom function DB  == Registered custom function DB_EXISTS  == Registered custom function TIMEOUT  == Registered custom function LANGUAGE  == Registered custom function MUSICCLASS  [pbx_spool.so] => (Outgoing Spool Support)  [pbx_config.so] => (Text Extension Configuration) Jul 4 16:59:46 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/extensions.conf Jul 4 16:59:46 WARNING[1729]: pbx.c:3742 ast_merge_contexts_and_delete: Requested contexts didn't get merged  [pbx_dundi.so] => (Distributed Universal Number Discovery (DUNDi)) Jul 4 16:59:46 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/dundi.conf Jul 4 16:59:46 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 16:59:46 DEBUG[1729]: pbx_dundi.c:422 reset_global_eid: Seeding global EID '00:13:d4:b2:b4:c6' from 'eth0'  == Using TOS bits 0 Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for N06Ltbfx3pa9gc7P@192.168.0.245 - REGISTER (No RTP)  == DUNDi Ready and Listening on 0.0.0.0 port 4520 Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER  == Registered application 'DUNDiLookup'  == Registered custom function DUNDILOOKUP  [pbx_loopback.so]Jul 4 16:59:46 DEBUG[1742]: res_config_mysql.c:125 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE name = '3002' => (Loopback Switch) Jul 4 16:59:46 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine.  [app_txtcidname.so] => (TXTCIDName)  == Registered application 'TXTCIDName'  [format_h263.so] => (Raw h263 data)  == Registered file format h263, extension(s) h263  [cdr_csv.so] => (Comma Separated Values CDR Backend)  [skipping codec_speex.so]  [skipping res_config_odbc.so]  [format_sln.so] => (Raw Signed Linear Audio support (SLN))  == Registered file format sln, extension(s) sln|raw  [app_queue.so] -- SIP Seeding peer from astdb: '3002' at 3002@192.168.0.245:5060 for 60  => (True Call Queueing)  == Registered application 'Queue'  == Manager registered action Queues  == Manager registered action QueueStatus  == Manager registered action QueueAdd  == Manager registered action QueueRemove  -- Message count requested for mailbox 3002 but voicemail not loaded.  == Manager registered action QueuePause  == Registered application 'AddQueueMember'  == Registered application 'RemoveQueueMember'  == Registered application 'PauseQueueMember'  == Registered application 'UnpauseQueueMember'  == Registered application 'HaveAgentsAvailable'  == Registered custom function QUEUEAGENTCOUNT Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 16:59:46 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/queues.conf Jul 4 16:59:46 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 16:59:46 WARNING[1729]: app_queue.c:588 create_queue_member_name: Agent Number: 40005 Jul 4 16:59:46 WARNING[1729]: app_queue.c:588 create_queue_member_name: Agent Number: 40008 Jul 4 16:59:46 WARNING[1729]: app_queue.c:588 create_queue_member_name: Agent Number: 40009 Jul 4 16:59:46 WARNING[1729]: app_queue.c:588 create_queue_member_name: Agent Number: 40010 Jul 4 16:59:46 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/queue_mysql.conf Connecting with mysql Jul 4 16:59:46 NOTICE[1729]: app_queue.c:4288 appqu_load_module: queue_mysql (billy): got hname of 192.168.0.200 Jul 4 16:59:46 NOTICE[1729]: app_queue.c:4289 appqu_load_module: queue_mysql (billy): got port of 3306 Jul 4 16:59:46 NOTICE[1729]: app_queue.c:4291 appqu_load_module: queue_mysql (billy): got sock file of /tmp/mysql.sock Jul 4 16:59:46 NOTICE[1729]: app_queue.c:4292 appqu_load_module: queue_mysql (billy): got user of root Jul 4 16:59:46 NOTICE[1729]: app_queue.c:4293 appqu_load_module: queue_mysql (billy): got dbname of dipdb Jul 4 16:59:46 NOTICE[1729]: app_queue.c:4294 appqu_load_module: queue_mysql (billy): got password of strong Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 311074372284b6c23eb16dfa18f94edd@192.168.0.201 Their Tag Our tag: as2f03ba23 Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: N06Ltbfx3pa9gc7P@192.168.0.245 Their Tag Yg16OWNAg2cvGexs Our tag: as7f8e2c09 Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER  -- Saved useragent "SOYO,Inc." for peer 3002 Jul 4 16:59:46 DEBUG[1742]: res_config_mysql.c:321 update_mysql: MySQL RealTime: Update SQL: UPDATE sip SET ipaddr = '192.168.0.245', port = '5060', regseconds = '1152043246', username = '3002', fullcontact = 'sip:3002@192.168.0.245:5060' WHERE name = '3002' Jul 4 16:59:46 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 16:59:46 DEBUG[1742]: res_config_mysql.c:341 update_mysql: MySQL RealTime: Updated 1 rows on table: sip Jul 4 16:59:46 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3002 Jul 4 16:59:46 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3002 - state 1 (Not in use) Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 311074372284b6c23eb16dfa18f94edd@192.168.0.201 Their Tag Our tag: as2f03ba23 Jul 4 16:59:46 DEBUG[1746]: app_queue.c:502 changethread: Device 'SIP/3002' changed to state '1' (Not in use) Jul 4 16:59:46 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '311074372284b6c23eb16dfa18f94edd@192.168.0.201' of Request 102: Match Found Jul 4 16:59:56 NOTICE[1729]: app_queue.c:4303 appqu_load_module: Successfully connected to MySQL database.  [format_vox.so] => (Dialogic VOX (ADPCM) File Format)  == Registered file format vox, extension(s) vox  [app_nbscat.so] => (Silly NBS Stream Application)  == Registered application 'NBScat'  [format_pcm.so] => (Raw uLaw 8khz Audio support (PCM))  == Registered file format pcm, extension(s) pcm|ulaw|ul|mu  [app_meetme.so] => (MeetMe conference bridge) Jul 4 16:59:56 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/meetme.conf  == Registered application 'MeetMeAdmin'  == Registered application 'MeetMeCount'  == Registered application 'MeetMe'  [codec_ulaw.so] => (Mu-law Coder/Decoder) Jul 4 16:59:56 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/codecs.conf  -- codec_ulaw: using generic PLC  == Registered translator 'ulawtolin' from format ulaw to slin, cost 1 Jul 4 16:59:56 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix  == Registered translator 'lintoulaw' from format slin to ulaw, cost 1 Jul 4 16:59:56 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix  [skipping chan_skinny.so]  [app_hasnewvoicemail.so] => (Indicator for whether a voice mailbox has messages in a given folder.[)  == Registered custom function VMCOUNT  == Registered application 'HasVoicemail'  == Registered application 'HasNewVoicemail'  [app_setrdnis.so] => (Set RDNIS Number)  == Registered application 'SetRDNIS'  [app_url.so] => (Send URL Applications)  == Registered application 'SendURL'  [skipping cdr_odbc.so]  [format_ogg_vorbis.so] => (OGG/Vorbis audio)  == Registered file format ogg_vorbis, extension(s) ogg  [app_db.so] => (Database Access Functions)  == Registered application 'DBget'  == Registered application 'DBput'  == Registered application 'DBdel'  == Registered application 'DBdeltree'  [app_disa.so] => (DISA (Direct Inward System Access) Application)  == Registered application 'DISA'  [app_lookupblacklist.so] => (Look up Caller*ID name/number from blacklist database)  == Registered application 'LookupBlacklist'  [app_getcpeid.so] => (Get ADSI CPE ID)  == Registered application 'GetCPEID'  [app_mp3.so] => (Silly MP3 Application)  == Registered application 'MP3Player'  [app_directed_pickup.so] => (Directed Call Pickup Application)  == Registered application 'Pickup'  [cdr_manager.so] => (Asterisk Call Manager CDR Backend) Jul 4 16:59:56 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/cdr_manager.conf  [app_sms.so] => (SMS/PSTN handler)  == Registered application 'SMS'  [skipping chan_oss.so]  [app_test.so] => (Interface Test Application)  == Registered application 'TestClient'  == Registered application 'TestServer'  [app_stack.so] => (Stack Routines)  == Registered application 'StackPop'  == Registered application 'Return'  == Registered application 'GosubIf'  == Registered application 'Gosub'  [skipping codec_g726.so]  [app_saycountpl.so] => (Say polish counting words)  == Registered application 'SayCountPL'  [skipping chan_mgcp.so]  [app_lookupcidname.so] => (Look up CallerID Name from local database)  == Registered application 'LookupCIDName'  [format_gsm.so] => (Raw GSM data)  == Registered file format gsm, extension(s) gsm  [app_realtime.so] => (Realtime Data Lookup/Rewrite)  == Registered application 'RealTimeUpdate'  == Registered application 'RealTime'  [codec_gsm.so] => (GSM/PCM16 (signed linear) Codec Translator) Jul 4 16:59:56 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/codecs.conf  -- codec_gsm: using generic PLC  == Registered translator 'gsmtolin' from format gsm to slin, cost 1 Jul 4 16:59:56 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 16:59:56 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6  == Registered translator 'lintogsm' from format slin to gsm, cost 2 Jul 4 16:59:56 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 16:59:56 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 16:59:56 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6  [format_g729.so] => (Raw G729 data)  == Registered file format g729, extension(s) g729  [app_setcidnum.so] => (Set CallerID Number)  == Registered application 'SetCIDNum'  [app_loqtts.so] => (Loquendo Text To Speech Application)  == Registered application 'LoqTTS'  [app_dial.so] => (Dialing Application)  == Registered application 'Dial'  == Registered application 'RetryDial'  [app_parkandannounce.so] => (Call Parking and Announce Application)  == Registered application 'ParkAndAnnounce'  [skipping app_ices.so]  [app_curl.so] => (Load external URL)  == Registered custom function CURL  == Registered application 'Curl'  [app_setcidname.so] => (Set CallerID Name)  == Registered application 'SetCIDName'  [app_authenticate.so] => (Authentication Application)  == Registered application 'Authenticate'  [app_page.so] => (Page Multiple Phones)  == Registered application 'Page'  [app_sayunixtime.so] => (Say time)  == Registered application 'SayUnixTime'  == Registered application 'DateTime'  [app_softhangup.so] => (Hangs up the requested channel)  == Registered application 'SoftHangup'  [app_readfile.so] => (Stores output of file into a variable)  == Registered application 'ReadFile'  [app_verbose.so] => (Send verbose output)  == Registered application 'Verbose'  [app_talkdetect.so] => (Playback with Talk Detection)  == Registered application 'BackgroundDetect'  [app_while.so] => (While Loops and Conditional Execution)  == Registered application 'While'  == Registered application 'ExecIf'  == Registered application 'EndWhile'  [app_enumlookup.so] => (ENUM Lookup)  == Registered application 'EnumLookup' Jul 4 16:59:56 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/enum.conf  [app_playback.so] => (Sound File Playback Application)  == Registered application 'Playback'  [format_g723.so] => (G.723.1 Simple Timestamp File Format)  == Registered file format g723sf, extension(s) g723|g723sf  [skipping cdr_custom.so]  [app_setcallerid.so] => (Set CallerID Application)  == Registered application 'SetCallerPres'  == Registered application 'SetCallerID'  [app_exec.so] => (Executes applications)  == Registered application 'Exec'  [app_dictate.so] => (Virtual Dictation Machine)  == Registered application 'Dictate'  [app_setcdruserfield.so] => (CDR user field apps)  == Registered application 'SetCDRUserField'  == Registered application 'AppendCDRUserField'  == Manager registered action SetCDRUserField  [app_waitforsilence.so] => (Wait For Silence)  == Registered application 'WaitForSilence'  [func_uri.so] => (URI encode/decode functions)  == Registered custom function URIDECODE  == Registered custom function URIENCODE  [app_settransfercapability.so] => (Set ISDN Transfer Capability)  == Registered application 'SetTransferCapability'  [cdr_addon_mysql.so] => (MySQL CDR Backend) Jul 4 16:59:56 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/cdr_mysql.conf Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:433 my_load_module: cdr_mysql: got hostname of 192.168.0.200 Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:434 my_load_module: cdr_mysql: got port of 3306 Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:435 my_load_module: cdr_mysql: got a timeout of 0 Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:437 my_load_module: cdr_mysql: got sock file of /tmp/mysql.sock Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:438 my_load_module: cdr_mysql: got user of root Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:439 my_load_module: cdr_mysql: got dbname of dipdb Jul 4 16:59:56 DEBUG[1729]: cdr_addon_mysql.c:440 my_load_module: cdr_mysql: got password of strong Jul 4 16:59:57 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 16:59:57 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 16:59:57 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 1dbbbba61e61539d3d3b425f2ed0c617@192.168.0.201 Their Tag Our tag: as5d8e450f Jul 4 16:59:57 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '1dbbbba61e61539d3d3b425f2ed0c617@192.168.0.201' of Request 102: Match Found Jul 4 17:00:01 DEBUG[1742]: chan_sip.c:1311 __sip_autodestruct: Auto destroying call 'N06Ltbfx3pa9gc7P@192.168.0.245' Jul 4 17:00:06 DEBUG[1729]: cdr_addon_mysql.c:453 my_load_module: Successfully connected to MySQL database.  [cdr_pgsql.so] => (PostgreSQL CDR Backend) Jul 4 17:00:06 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/cdr_pgsql.conf  [format_au.so] => (Sun Microsystems AU format (signed linear))  == Registered file format au, extension(s) au  [app_chanspy.so] => (Listen to the audio of an active channel )  == Registered application 'ChanSpy'  [app_sendtext.so] => (Send Text Applications)  == Registered application 'SendText'  [format_g726.so] => (Raw G.726 (16/24/32/40kbps) data)  == Registered file format g726-40, extension(s) g726-40  == Registered file format g726-32, extension(s) g726-32  == Registered file format g726-24, extension(s) g726-24  == Registered file format g726-16, extension(s) g726-16  [app_zapateller.so] => (Block Telemarketers with Special Information Tone)  == Registered application 'Zapateller'  [format_wav.so] => (Microsoft WAV format (8000hz Signed Linear))  == Registered file format wav, extension(s) wav  [app_eval.so] => (Reevaluates strings)  == Registered application 'Eval'  [format_mp3.so] => (MP3 format [Any rate but 8000hz mono optimal])  == Registered file format mp3, extension(s) mp3  [app_image.so] => (Image Transmission Application)  == Registered application 'SendImage'  [app_random.so] => (Random goto)  == Registered application 'Random'  [codec_alaw.so] => (A-law Coder/Decoder) Jul 4 17:00:06 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/codecs.conf  -- codec_alaw: using generic PLC  == Registered translator 'alawtolin' from format alaw to slin, cost 1 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6  == Registered translator 'lintoalaw' from format slin to alaw, cost 1 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6  [app_math.so] => (Basic Math Functions)  == Registered application 'Math'  [skipping res_odbc.so]  [app_adsiprog.so] => (Asterisk ADSI Programming Application)  == Registered application 'ADSIProg'  [app_controlplayback.so] => (Control Playback Application)  == Registered application 'ControlPlayback'  [format_wav_gsm.so] => (Microsoft WAV format (Proprietary GSM))  == Registered file format wav49, extension(s) WAV|wav49  [skipping codec_lpc10.so]  [app_milliwatt.so] => (Digital Milliwatt (mu-law) Test Application)  == Registered application 'Milliwatt'  [app_macro.so] => (Extension Macros)  == Registered application 'MacroExit'  == Registered application 'MacroIf'  == Registered application 'Macro'  [app_txfax.so] => (Trivial FAX Transmit Application)  == Registered application 'TxFAX'  [codec_ilbc.so] => (iLBC/PCM16 (signed linear) Codec Translator)  == Registered translator 'ilbctolin' from format ilbc to slin, cost 68 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 70 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6  == Registered translator 'lintoilbc' from format slin to ilbc, cost 49 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 70 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6  [app_zapscan.so] => (Scan Zap channels application)  == Registered application 'ZapScan'  [app_voicemail.so] => (Comedian Mail (Voicemail System))  == Registered application 'VoiceMail'  == Registered application 'VoiceMailMain'  == Registered application 'MailboxExists'  == Registered application 'VMAuthenticate' Jul 4 17:00:06 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/voicemail.conf Jul 4 17:00:06 DEBUG[1729]: app_voicemail.c:6007 load_config: VM Review Option disabled globally Jul 4 17:00:06 DEBUG[1729]: app_voicemail.c:6013 load_config: VM Operator break disabled globally Jul 4 17:00:06 DEBUG[1729]: app_voicemail.c:6019 load_config: VM CID Info before msg disabled globally Jul 4 17:00:06 DEBUG[1729]: app_voicemail.c:6031 load_config: ENVELOPE before msg enabled globally Jul 4 17:00:06 DEBUG[1729]: app_voicemail.c:6037 load_config: Duration info before msg enabled globally Jul 4 17:00:06 DEBUG[1729]: app_voicemail.c:6052 load_config: We are not going to skip to the next msg after save/delete  [app_userevent.so] => (Custom User Event Application)  == Registered application 'UserEvent'  [app_flash.so] => (Flash zap trunk application)  == Registered application 'Flash'  [app_cdr.so] => (Tell Asterisk to not maintain a CDR for the current call)  == Registered application 'NoCDR'  [app_read.so] => (Read Variable Application)  == Registered application 'Read'  [app_chanisavail.so] => (Check channel availability)  == Registered application 'ChanIsAvail'  [func_callerid.so] => (Caller ID related dialplan function)  == Registered custom function CALLERID  [app_record.so] => (Trivial Record Application)  == Registered application 'Record'  [skipping app_festival.so]  [format_ilbc.so] => (Raw iLBC data)  == Registered file format iLBC, extension(s) ilbc  [app_externalivr.so] => (External IVR Interface Application)  == Registered application 'ExternalIVR'  [app_directory.so] => (Extension Directory)  == Registered application 'Directory'  [app_senddtmf.so] => (Send DTMF digits Application)  == Registered application 'SendDTMF'  [app_system.so] => (Generic System() application)  == Registered application 'TrySystem'  == Registered application 'System'  [skipping chan_alsa.so]  [app_zapbarge.so] => (Barge in on Zap channel application)  == Registered application 'ZapBarge'  [app_md5.so] => (MD5 checksum applications)  == Registered application 'MD5Check'  == Registered application 'MD5'  [app_waitforring.so] => (Waits until first ring after time)  == Registered application 'WaitForRing'  [func_enum.so] => (ENUM Related Functions)  == Registered custom function ENUMLOOKUP  == Registered custom function TXTCIDNAME  [app_cut.so] => (Cut out information from a string)  == Registered custom function CUT  == Registered custom function SORT  == Registered application 'Sort'  == Registered application 'Cut'  [app_zapras.so] => (Zap RAS Application)  == Registered application 'ZapRAS'  [app_addon_sql_mysql.so] => (Simple Mysql Interface)  == Registered application 'MYSQL'  [format_pcm_alaw.so] => (Raw aLaw 8khz PCM Audio support)  == Registered file format alaw, extension(s) alaw|al  [app_transfer.so] => (Transfer)  == Registered application 'Transfer'  [app_echo.so] => (Simple Echo Application)  == Registered application 'Echo'  [skipping chan_unicall.so]  [app_rxfax.so] => (Trivial FAX Receive Application)  == Registered application 'RxFAX'  [app_privacy.so] => (Require phone number to be entered, if no CallerID sent)  == Registered application 'PrivacyManager'  [app_dumpchan.so] => (Dump Info About The Calling Channel)  == Registered application 'DumpChan'  [codec_adpcm.so] => (Adaptive Differential PCM Coder/Decoder) Jul 4 17:00:06 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/codecs.conf  -- codec_adpcm: using generic PLC  == Registered translator 'adpcmtolin' from format adpcm to slin, cost 1 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 70 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6  == Registered translator 'lintoadpcm' from format slin to adpcm, cost 1 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 70 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6  [app_alarmreceiver.so] => (Alarm Receiver for Asterisk) Jul 4 17:00:06 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/alarmreceiver.conf  == Registered application 'AlarmReceiver'  [codec_a_mu.so] => (A-law and Mulaw direct Coder/Decoder)  == Registered translator 'alawtoulaw' from format alaw to ulaw, cost 1 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 4 cost path from unknown to g723, via 2 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to unknown, via 2 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 2 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 70 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6  == Registered translator 'ulawtoalaw' from format ulaw to alaw, cost 1 Jul 4 17:00:06 DEBUG[1729]: translate.c:277 rebuild_matrix: Resetting translation matrix Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from g723 to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from gsm to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from gsm to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 4 cost path from unknown to g723, via 2 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to unknown, via 2 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 2 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 3 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 50 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 70 cost path from unknown to g723, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to gsm, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6 Jul 4 17:00:06 DEBUG[1729]: translate.c:314 rebuild_matrix: Discovered 69 cost path from unknown to unknown, via 6  [format_jpeg.so] => (JPEG (Joint Picture Experts Group) Image Format)  == Registered format 'jpg' (JPEG (Joint Picture Experts Group))  [app_forkcdr.so] => (Fork The CDR into 2 separate entities.)  == Registered application 'ForkCDR'  [app_groupcount.so] => (Group Management Routines)  == Registered application 'GetGroupCount'  == Registered application 'SetGroup'  == Registered application 'CheckGroup'  == Registered application 'GetGroupMatchCount'  == Manager registered action DBGet  == Manager registered action DBPut Jul 4 17:00:06 DEBUG[1729]: config.c:595 config_text_file_load: Parsing /dip/etc/enum.conf DIP Ready. ]1;DIP]2;DIP Console on 'localhost.localdomain' (pid 1729)*DIP> -- Remote UNIX connection  -- Remote UNIX connection disconnected Jul 4 17:00:17 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.244 with 192.168.0.0 Jul 4 17:00:17 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 - REGISTER (No RTP) Jul 4 17:00:17 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Jul 4 17:00:17 DEBUG[1742]: res_config_mysql.c:125 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE name = '3005' Jul 4 17:00:17 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine.  -- SIP Seeding peer from astdb: '3005' at @192.168.0.244:12714 for 120 Jul 4 17:00:17 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 17:00:17 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.244 with 192.168.0.0 Jul 4 17:00:17 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 110649bb2eea8a5e0dd3a3a57ce94a5d@192.168.0.201 Their Tag Our tag: as680bd8de Jul 4 17:00:17 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 Their Tag b88e8aa8e9dd48aaa7b3224457161b4c Our tag: as0dd0797b Jul 4 17:00:17 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER  -- Saved useragent "RTC/1.2.4949" for peer 3005 Jul 4 17:00:18 DEBUG[1742]: res_config_mysql.c:321 update_mysql: MySQL RealTime: Update SQL: UPDATE sip SET ipaddr = '192.168.0.244', port = '12714', regseconds = '1152043338', username = '', fullcontact = 'sip:192.168.0.244:12714' WHERE name = '3005' Jul 4 17:00:18 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:00:18 DEBUG[1742]: res_config_mysql.c:341 update_mysql: MySQL RealTime: Updated 1 rows on table: sip Jul 4 17:00:18 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3005 Jul 4 17:00:18 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 110649bb2eea8a5e0dd3a3a57ce94a5d@192.168.0.201 Their Tag Our tag: as680bd8de Jul 4 17:00:18 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3005 - state 1 (Not in use) Jul 4 17:00:18 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '110649bb2eea8a5e0dd3a3a57ce94a5d@192.168.0.201' of Request 102: Match Found  -- Got SIP response 481 "Call Leg/Transaction Does Not Exist" back from 192.168.0.244 Jul 4 17:00:18 DEBUG[1758]: app_queue.c:502 changethread: Device 'SIP/3005' changed to state '1' (Not in use)  -- Remote UNIX connection Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 17:00:28 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.244 with 192.168.0.0 Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: NOTIFY sip:192.168.0.244:12714 SIP/2.0 (38) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7ef7d5df;rport (64) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as5111a489 (60) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: (29) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Contact: (37) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 1189d6a6380c67591b94f54f50b399e4@192.168.0.201 (55) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 102 NOTIFY (16) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: Dialtech IP PBX (27) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Max-Forwards: 70 (16) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Event: message-summary (22) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Type: application/simple-message-summary (48) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 80 (18) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Messages-Waiting: no (20) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Message-Account: sip:asterisk@ (30) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Voice-Message: 0/0 (0/0) (24) 12 headers, 3 lines Reliably Transmitting (no NAT) to 192.168.0.244:12714: NOTIFY sip:192.168.0.244:12714 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7ef7d5df;rport From: "asterisk" ;tag=as5111a489 To: Contact: Call-ID: 1189d6a6380c67591b94f54f50b399e4@192.168.0.201 CSeq: 102 NOTIFY User-Agent: Dialtech IP PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 80 Messages-Waiting: no Message-Account: sip:asterisk@ Voice-Message: 0/0 (0/0) --- Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #15 Scheduling destruction of call '1189d6a6380c67591b94f54f50b399e4@192.168.0.201' in 15000 ms <-- SIP read from 192.168.0.244:4193: SIP/2.0 481 Call Leg/Transaction Does Not Exist Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7ef7d5df;rport From: "asterisk" ;tag=as5111a489 To: ;tag=91a0821756734e2fa80e13f60fa3f66d Call-ID: 1189d6a6380c67591b94f54f50b399e4@192.168.0.201 CSeq: 102 NOTIFY User-Agent: RTC/1.2 Content-Length: 0 Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 481 Call Leg/Transaction Does Not Exist (47) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7ef7d5df;rport (64) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as5111a489 (60) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: ;tag=91a0821756734e2fa80e13f60fa3f66d (66) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 1189d6a6380c67591b94f54f50b399e4@192.168.0.201 (55) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: CSeq: 102 NOTIFY (16) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: User-Agent: RTC/1.2 (19) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 1189d6a6380c67591b94f54f50b399e4@192.168.0.201 Their Tag Our tag: as5111a489 Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #15 Jul 4 17:00:28 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '1189d6a6380c67591b94f54f50b399e4@192.168.0.201' of Request 102: Match Found  -- Got SIP response 481 "Call Leg/Transaction Does Not Exist" back from 192.168.0.244 Destroying call '1189d6a6380c67591b94f54f50b399e4@192.168.0.201'  -- Remote UNIX connection disconnected <-- SIP read from 192.168.0.101:5060: Jul 4 17:00:31 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:00:33 DEBUG[1742]: chan_sip.c:1311 __sip_autodestruct: Auto destroying call 'c4e58c2cf132461fa13127dd685d5dab@192.168.0.244' Destroying call 'c4e58c2cf132461fa13127dd685d5dab@192.168.0.244' <-- SIP read from 192.168.0.101:5060: Jul 4 17:00:36 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- <-- SIP read from 192.168.0.101:5060: INVITE sip:3002@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK4059965979 From: "anonymous" ;tag=1496440117 To: Call-ID: 1516397444@192.168.0.101 CSeq: 1000 INVITE Contact: max-forwards: 70 user-agent: UTSTARCOM F1000/Device ID-0007ba252d95 Content-Type: application/sdp Content-Length: 300 v=0 o=3050 123456 654328 IN IP4 192.168.0.101 s=none c=IN IP4 192.168.0.101 t=0 0 m=audio 10010 RTP/AVP 0 8 18 96 101 a=ptime:20 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729A/8000 a=fmtp:18 annexb=no a=rtpmap:96 G726/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: INVITE sip:3002@192.168.0.201 SIP/2.0 (37) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK4059965979 (66) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "anonymous" ;tag=1496440117 (57) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: (28) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 1516397444@192.168.0.101 (33) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: CSeq: 1000 INVITE (17) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Contact: (38) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: max-forwards: 70 (16) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: user-agent: UTSTARCOM F1000/Device ID-0007ba252d95 (50) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Content-Type: application/sdp (29) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Length: 300 (21) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: (0) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: v=0 (3) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: o=3050 123456 654328 IN IP4 192.168.0.101 (41) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: s=none (6) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: c=IN IP4 192.168.0.101 (22) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: t=0 0 (5) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: m=audio 10010 RTP/AVP 0 8 18 96 101 (35) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=ptime:20 (10) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:18 G729A/8000 (22) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:18 annexb=no (19) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:96 G726/8000 (21) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 14 lines)--- Jul 4 17:00:42 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.101 with 192.168.0.0 Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for 1516397444@192.168.0.101 - INVITE (With RTP) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 1516397444@192.168.0.101 Sending to 192.168.0.101 : 5060 (non-NAT) Jul 4 17:00:42 DEBUG[1742]: res_config_mysql.c:125 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE name = '3050' Jul 4 17:00:42 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:7010 check_user_full: Setting NAT on RTP to 0 Found user '3050' Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 96 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.101:10010 Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3501 process_sdp: Peer audio RTP is at port 192.168.0.101:10010 Found description format PCMU Found description format PCMA Found description format G729A Found description format G726 Found description format telephone-event Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:10320 handle_request_invite: Checking SIP call limits for device 3050 Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:2195 update_call_counter: Updating call counter for incoming call Looking for 3002 in from-sip (domain 192.168.0.201) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:6025 build_route: build_route: Contact hop: list_route: hop: Transmitting (no NAT) to 192.168.0.101:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK4059965979;received=192.168.0.101 From: "anonymous" ;tag=1496440117 To: Call-ID: 1516397444@192.168.0.101 CSeq: 1000 INVITE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Jul 4 17:00:42 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3050 Jul 4 17:00:42 DEBUG[1761]: pbx.c:1667 pbx_extension_helper: Launching 'Dial'  -- Executing Dial("SIP/3050-2c24", "SIP/3002|60|rtTwW") in new stack Jul 4 17:00:42 DEBUG[1735]: res_config_mysql.c:125 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE name = '3050' Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:1860 create_addr_from_peer: Setting NAT on RTP to 0 Jul 4 17:00:42 DEBUG[1735]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:00:42 DEBUG[1761]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 17:00:42 DEBUG[1761]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-from-sip-3002-1. Jul 4 17:00:42 DEBUG[1761]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPCALLID. Jul 4 17:00:42 DEBUG[1761]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Jul 4 17:00:42 DEBUG[1761]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Jul 4 17:00:42 DEBUG[1761]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPURI.  -- SIP Seeding peer from astdb: '3050' at 3050@192.168.0.101:5060 for 1332 Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:2054 sip_call: Outgoing Call for 3002 Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:2195 update_call_counter: Updating call counter for outgoing call Jul 4 17:00:42 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3050 - state 2 (In use) We're at 192.168.0.201 port 11366 Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jul 4 17:00:42 DEBUG[1763]: app_queue.c:502 changethread: Device 'SIP/3050' changed to state '2' (In use) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 0: INVITE sip:3002@192.168.0.245:5060 SIP/2.0 (42) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK052bfe92;rport (64) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 2: From: "anonymous" ;tag=as0a6c366f (60) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 3: To: (33) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 4: Contact: (36) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 (55) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 6: CSeq: 102 INVITE (16) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 7: User-Agent: Dialtech IP PBX (27) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 8: Max-Forwards: 70 (16) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 9: Date: Tue, 04 Jul 2006 20:00:42 GMT (35) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 11: Content-Type: application/sdp (29) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 12: Content-Length: 263 (19) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3317 parse_request: Header 13: (0) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: v=0 (3) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: o=root 1729 1729 IN IP4 192.168.0.201 (37) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: s=session (9) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: c=IN IP4 192.168.0.201 (22) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: t=0 0 (5) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: m=audio 11366 RTP/AVP 0 3 8 101 (31) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: a=fmtp:101 0-16 (15) Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:3349 parse_request: Line: a=silenceSupp:off - - - - (25) 13 headers, 12 lines Reliably Transmitting (no NAT) to 192.168.0.245:5060: INVITE sip:3002@192.168.0.245:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK052bfe92;rport From: "anonymous" ;tag=as0a6c366f To: Contact: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 CSeq: 102 INVITE User-Agent: Dialtech IP PBX Max-Forwards: 70 Date: Tue, 04 Jul 2006 20:00:42 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 263 v=0 o=root 1729 1729 IN IP4 192.168.0.201 s=session c=IN IP4 192.168.0.201 t=0 0 m=audio 11366 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 4 17:00:42 DEBUG[1761]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18  -- Called 3002 Transmitting (no NAT) to 192.168.0.101:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK4059965979;received=192.168.0.101 From: "anonymous" ;tag=1496440117 To: ;tag=as5e7a4f18 Call-ID: 1516397444@192.168.0.101 CSeq: 1000 INVITE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- <-- SIP read from 192.168.0.245:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK052bfe92;rport Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 CSeq: 102 INVITE From: "anonymous" ;tag=as0a6c366f To: ;tag=e5lHIHe8KAbQvGna Contact: Content-Length: 0 Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK052bfe92;rport (64) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 (55) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: CSeq: 102 INVITE (16) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: From: "anonymous" ;tag=as0a6c366f (60) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: To: ;tag=e5lHIHe8KAbQvGna (54) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Contact: (38) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag Our tag: as0a6c366f Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:1433 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #18 - INVITE (got response) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:1442 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '7ef561b14298c22b2b5b1b3302f10448@192.168.0.201' Request 102: Found Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:9426 handle_response_invite: SIP response 180 to standard invite  -- SIP/3002-e829 is ringing Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 17:00:42 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3002 Jul 4 17:00:42 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.101 with 192.168.0.0 Jul 4 17:00:42 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3002 - state 6 (Ringing) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: NOTIFY sip:3050@192.168.0.101:5060 SIP/2.0 (42) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK33666fc2;rport (64) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as236fbf19 (60) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: (33) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Contact: (37) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 4d23f12a1857c03135def97d394afaac@192.168.0.201 (55) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 102 NOTIFY (16) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: Dialtech IP PBX (27) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Max-Forwards: 70 (16) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Event: message-summary (22) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Type: application/simple-message-summary (48) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 80 (18) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Messages-Waiting: no (20) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Message-Account: sip:asterisk@ (30) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Voice-Message: 0/0 (0/0) (24) 12 headers, 3 lines Reliably Transmitting (no NAT) to 192.168.0.101:5060: NOTIFY sip:3050@192.168.0.101:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK33666fc2;rport From: "asterisk" ;tag=as236fbf19 To: Contact: Call-ID: 4d23f12a1857c03135def97d394afaac@192.168.0.201 CSeq: 102 NOTIFY User-Agent: Dialtech IP PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 80 Messages-Waiting: no Message-Account: sip:asterisk@ Voice-Message: 0/0 (0/0) --- Jul 4 17:00:42 DEBUG[1764]: app_queue.c:502 changethread: Device 'SIP/3002' changed to state '6' (Ringing) Jul 4 17:00:42 DEBUG[1742]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #19 Scheduling destruction of call '4d23f12a1857c03135def97d394afaac@192.168.0.201' in 15000 ms <-- SIP read from 192.168.0.101:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK33666fc2;rport=5060 From: "asterisk" ;tag=as236fbf19 To: ;tag=4042459322 Call-ID: 4d23f12a1857c03135def97d394afaac@192.168.0.201 CSeq: 102 NOTIFY Contact: Content-Length: 0 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK33666fc2;rport=5060 (69) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as236fbf19 (60) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: ;tag=4042459322 (48) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 4d23f12a1857c03135def97d394afaac@192.168.0.201 (55) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: CSeq: 102 NOTIFY (16) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Contact: (38) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 4d23f12a1857c03135def97d394afaac@192.168.0.201 Their Tag Our tag: as236fbf19 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #19 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '4d23f12a1857c03135def97d394afaac@192.168.0.201' of Request 102: Match Found Destroying call '4d23f12a1857c03135def97d394afaac@192.168.0.201' <-- SIP read from 192.168.0.245:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK052bfe92;rport Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 CSeq: 102 INVITE From: "anonymous" ;tag=as0a6c366f To: ;tag=e5lHIHe8KAbQvGna Contact: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, REFER, NOTIFY, INFO, PRACK Supported: 100rel, replaces Content-Type: application/sdp Content-Length: 181 v=0 o=- 0 0 IN IP4 192.168.0.245 s=SIP CALL c=IN IP4 192.168.0.245 t=0 0 m=audio 10005 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK052bfe92;rport (64) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 (55) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: CSeq: 102 INVITE (16) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: From: "anonymous" ;tag=as0a6c366f (60) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: To: ;tag=e5lHIHe8KAbQvGna (54) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Contact: (38) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Allow: INVITE, ACK, OPTIONS, BYE, CANCEL, REGISTER, REFER, NOTIFY, INFO, PRACK (78) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Supported: 100rel, replaces (27) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Content-Type: application/sdp (29) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Length: 181 (19) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: (0) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: v=0 (3) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: o=- 0 0 IN IP4 192.168.0.245 (28) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: s=SIP CALL (10) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: c=IN IP4 192.168.0.245 (22) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: t=0 0 (5) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: m=audio 10005 RTP/AVP 0 101 (27) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines)--- Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag e5lHIHe8KAbQvGna Our tag: as0a6c366f Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:1367 __sip_ack: Acked pending invite 102 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '7ef561b14298c22b2b5b1b3302f10448@192.168.0.201' of Request 102: Match Found Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:9426 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.245:10005 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3501 process_sdp: Peer audio RTP is at port 192.168.0.245:10005 Found description format PCMU Found description format telephone-event Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3598 process_sdp: Oooh, we need to change our formats since our peer supports only 0x4 (ulaw) and not 0x2 (gsm) Jul 4 17:00:43 DEBUG[1742]: channel.c:2475 set_format: Set channel SIP/3002-e829 to read format gsm Jul 4 17:00:43 DEBUG[1742]: channel.c:2475 set_format: Set channel SIP/3002-e829 to write format gsm Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:6025 build_route: build_route: Contact hop: list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.245, port 5060 Transmitting (no NAT) to 192.168.0.245:5060: ACK sip:3002@192.168.0.245:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK75f31b57;rport From: "anonymous" ;tag=as0a6c366f To: ;tag=e5lHIHe8KAbQvGna Contact: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 CSeq: 102 ACK User-Agent: Dialtech IP PBX Max-Forwards: 70 Content-Length: 0 ---  -- SIP/3002-e829 answered SIP/3050-2c24 Jul 4 17:00:43 DEBUG[1761]: channel.c:2475 set_format: Set channel SIP/3050-2c24 to read format ulaw Jul 4 17:00:43 DEBUG[1761]: channel.c:2475 set_format: Set channel SIP/3002-e829 to write format ulaw Jul 4 17:00:43 DEBUG[1761]: channel.c:2475 set_format: Set channel SIP/3002-e829 to read format ulaw Jul 4 17:00:43 DEBUG[1761]: channel.c:2475 set_format: Set channel SIP/3050-2c24 to write format ulaw Jul 4 17:00:43 DEBUG[1761]: chan_sip.c:2505 sip_answer: sip_answer(SIP/3050-2c24) We're at 192.168.0.201 port 15994 Adding codec 0x2 (gsm) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (no NAT) to 192.168.0.101:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK4059965979;received=192.168.0.101 From: "anonymous" ;tag=1496440117 To: ;tag=as5e7a4f18 Call-ID: 1516397444@192.168.0.101 CSeq: 1000 INVITE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Type: application/sdp Content-Length: 263 v=0 o=root 1729 1729 IN IP4 192.168.0.201 s=session c=IN IP4 192.168.0.201 t=0 0 m=audio 15994 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 4 17:00:43 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3002 Jul 4 17:00:43 DEBUG[1761]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21  -- Attempting native bridge of SIP/3050-2c24 and SIP/3002-e829 Jul 4 17:00:43 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3002 - state 2 (In use) Jul 4 17:00:43 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3050 Jul 4 17:00:43 DEBUG[1765]: app_queue.c:502 changethread: Device 'SIP/3002' changed to state '2' (In use) Jul 4 17:00:43 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3050 - state 2 (In use) Jul 4 17:00:43 DEBUG[1766]: app_queue.c:502 changethread: Device 'SIP/3050' changed to state '2' (In use) Jul 4 17:00:43 DEBUG[1761]: rtp.c:1341 ast_rtp_write: Ooh, format changed from unknown to ulaw Jul 4 17:00:43 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 64 bytes Jul 4 17:00:43 DEBUG[1761]: rtp.c:1341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.0.101:5060: ACK sip:3002@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK1706150177 From: "anonymous" ;tag=1496440117 To: ;tag=as5e7a4f18 Call-ID: 1516397444@192.168.0.101 CSeq: 1000 ACK max-forwards: 70 user-agent: UTSTARCOM F1000/Device ID-0007ba252d95 Content-Length: 0 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: ACK sip:3002@192.168.0.201 SIP/2.0 (34) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK1706150177 (66) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "anonymous" ;tag=1496440117 (57) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: ;tag=as5e7a4f18 (43) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 1516397444@192.168.0.101 (33) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: CSeq: 1000 ACK (14) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: max-forwards: 70 (16) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: user-agent: UTSTARCOM F1000/Device ID-0007ba252d95 (50) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Content-Length: 0 (17) Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag e5lHIHe8KAbQvGna Our tag: as0a6c366f Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 1516397444@192.168.0.101 Their Tag 1496440117 Our tag: as5e7a4f18 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #21 Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '1516397444@192.168.0.101' of Response 1000: Match Found <-- SIP read from 192.168.0.101:5060: Jul 4 17:00:43 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- <-- SIP read from 192.168.0.245:5060: REGISTER sip:192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bK9ySEFAow2 Max-Forwards: 70 User-Agent: SOYO,Inc. From: 3002 ;tag=HZDuycGeqkyppaHF To: 3002 Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 CSeq: 1173 REGISTER Contact: Expires: 60 Content-Length: 0 Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: REGISTER sip:192.168.0.201 SIP/2.0 (34) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bK9ySEFAow2 (59) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: User-Agent: SOYO,Inc. (21) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: From: 3002 ;tag=HZDuycGeqkyppaHF (56) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: To: 3002 (33) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 (39) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: CSeq: 1173 REGISTER (19) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Contact: (38) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Expires: 60 (11) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Length: 0 (17) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag e5lHIHe8KAbQvGna Our tag: as0a6c366f Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 1516397444@192.168.0.101 Their Tag 1496440117 Our tag: as5e7a4f18 Jul 4 17:00:47 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for N06Ltbfx3pa9gc7P@192.168.0.245 - REGISTER (No RTP) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.0.245 : 5060 (non-NAT) Transmitting (no NAT) to 192.168.0.245:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bK9ySEFAow2;received=192.168.0.245 From: 3002 ;tag=HZDuycGeqkyppaHF To: 3002 Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 CSeq: 1173 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Transmitting (no NAT) to 192.168.0.245:5060: SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bK9ySEFAow2;received=192.168.0.245 From: 3002 ;tag=HZDuycGeqkyppaHF To: 3002 ;tag=as0f3e6eab Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 CSeq: 1173 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: WWW-Authenticate: Digest realm="asterisk", nonce="4ac88d18" Content-Length: 0 --- Scheduling destruction of call 'N06Ltbfx3pa9gc7P@192.168.0.245' in 15000 ms <-- SIP read from 192.168.0.245:5060: REGISTER sip:192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bKOnX02fxXK Max-Forwards: 70 User-Agent: SOYO,Inc. From: 3002 ;tag=dO08cELkOk6jpfsn To: 3002 Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 CSeq: 1174 REGISTER Contact: Expires: 60 Authorization: Digest username="3002", realm="asterisk", nonce="4ac88d18", uri="sip:192.168.0.201", response="b246c525128f5ae69952431dc4a94206" Content-Length: 0 Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: REGISTER sip:192.168.0.201 SIP/2.0 (34) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bKOnX02fxXK (59) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: User-Agent: SOYO,Inc. (21) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: From: 3002 ;tag=dO08cELkOk6jpfsn (56) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: To: 3002 (33) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 (39) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: CSeq: 1174 REGISTER (19) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Contact: (38) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Expires: 60 (11) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Authorization: Digest username="3002", realm="asterisk", nonce="4ac88d18", uri="sip:192.168.0.201", response="b246c525128f5ae69952431dc4a94206" (143) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 0 (17) Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) --- (12 headers 0 lines)--- Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: N06Ltbfx3pa9gc7P@192.168.0.245 Their Tag HZDuycGeqkyppaHF Our tag: as0f3e6eab Jul 4 17:00:47 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.0.245 : 5060 (non-NAT) Transmitting (no NAT) to 192.168.0.245:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bKOnX02fxXK;received=192.168.0.245 From: 3002 ;tag=dO08cELkOk6jpfsn To: 3002 Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 CSeq: 1174 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Jul 4 17:00:47 DEBUG[1742]: res_config_mysql.c:321 update_mysql: MySQL RealTime: Update SQL: UPDATE sip SET ipaddr = '192.168.0.245', port = '5060', regseconds = '1152043307', username = '3002', fullcontact = 'sip:3002@192.168.0.245:5060' WHERE name = '3002' Jul 4 17:00:47 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:00:47 DEBUG[1742]: res_config_mysql.c:341 update_mysql: MySQL RealTime: Updated 1 rows on table: sip Transmitting (no NAT) to 192.168.0.245:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.245:5060;branch=z9hG4bKOnX02fxXK;received=192.168.0.245 From: 3002 ;tag=dO08cELkOk6jpfsn To: 3002 ;tag=as0f3e6eab Call-ID: N06Ltbfx3pa9gc7P@192.168.0.245 CSeq: 1174 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Expires: 60 Contact: ;expires=60 Date: Tue, 04 Jul 2006 20:00:47 GMT Content-Length: 0 --- Scheduling destruction of call 'N06Ltbfx3pa9gc7P@192.168.0.245' in 15000 ms Jul 4 17:00:47 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3002 Jul 4 17:00:47 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3002 - state 2 (In use) Jul 4 17:00:47 DEBUG[1767]: app_queue.c:502 changethread: Device 'SIP/3002' changed to state '2' (In use) Jul 4 17:00:48 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes <-- SIP read from 192.168.0.101:5060: Jul 4 17:00:49 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 17:00:52 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: NOTIFY sip:3002@192.168.0.245:5060 SIP/2.0 (42) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK20d01831;rport (64) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as4eb96488 (59) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: (33) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Contact: (36) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 07d6778d4b62bac4336e93a20b9892aa@192.168.0.201 (55) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 102 NOTIFY (16) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: Dialtech IP PBX (27) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Max-Forwards: 70 (16) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Event: message-summary (22) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Type: application/simple-message-summary (48) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 80 (18) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Messages-Waiting: no (20) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Message-Account: sip:asterisk@ (30) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Voice-Message: 0/0 (0/0) (24) 12 headers, 3 lines Reliably Transmitting (no NAT) to 192.168.0.245:5060: NOTIFY sip:3002@192.168.0.245:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK20d01831;rport From: "asterisk" ;tag=as4eb96488 To: Contact: Call-ID: 07d6778d4b62bac4336e93a20b9892aa@192.168.0.201 CSeq: 102 NOTIFY User-Agent: Dialtech IP PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 80 Messages-Waiting: no Message-Account: sip:asterisk@ Voice-Message: 0/0 (0/0) --- Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #25 Scheduling destruction of call '07d6778d4b62bac4336e93a20b9892aa@192.168.0.201' in 15000 ms <-- SIP read from 192.168.0.245:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK20d01831;rport Call-ID: 07d6778d4b62bac4336e93a20b9892aa@192.168.0.201 CSeq: 102 NOTIFY From: "asterisk" ;tag=as4eb96488 To: ;tag=zb2tIFxubtstSP24 Contact: Content-Length: 0 Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK20d01831;rport (64) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Call-ID: 07d6778d4b62bac4336e93a20b9892aa@192.168.0.201 (55) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: CSeq: 102 NOTIFY (16) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: From: "asterisk" ;tag=as4eb96488 (59) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: To: ;tag=zb2tIFxubtstSP24 (54) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Contact: (38) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 07d6778d4b62bac4336e93a20b9892aa@192.168.0.201 Their Tag Our tag: as4eb96488 Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #25 Jul 4 17:00:52 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '07d6778d4b62bac4336e93a20b9892aa@192.168.0.201' of Request 102: Match Found Destroying call '07d6778d4b62bac4336e93a20b9892aa@192.168.0.201' Jul 4 17:00:53 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes Jul 4 17:00:53 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 80 bytes <-- SIP read from 192.168.0.244:4193: INVITE sip:*553050@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 1 INVITE Contact: User-Agent: RTC/1.2 Content-Type: application/sdp Content-Length: 525 v=0 o=- 0 0 IN IP4 192.168.0.244 s=session c=IN IP4 192.168.0.244 b=CT:1000 t=0 0 m=audio 37776 RTP/AVP 97 111 112 6 0 8 4 5 3 101 k=base64:FE0iEBy71TRgKYggVC+S8KWeamXk/5sk/OsUGK9lz7Y a=rtpmap:97 red/8000 a=rtpmap:111 SIREN/16000 a=fmtp:111 bitrate=16000 a=rtpmap:112 G7221/16000 a=fmtp:112 bitrate=24000 a=rtpmap:6 DVI4/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=encryption:optional Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: INVITE sip:*553050@192.168.0.201 SIP/2.0 (40) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 (93) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: (31) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 (55) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 1 INVITE (14) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Contact: (34) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: User-Agent: RTC/1.2 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Content-Type: application/sdp (29) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Length: 525 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: (0) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: v=0 (3) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: o=- 0 0 IN IP4 192.168.0.244 (28) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: s=session (9) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: c=IN IP4 192.168.0.244 (22) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: b=CT:1000 (9) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: t=0 0 (5) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: m=audio 37776 RTP/AVP 97 111 112 6 0 8 4 5 3 101 (48) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: k=base64:FE0iEBy71TRgKYggVC+S8KWeamXk/5sk/OsUGK9lz7Y (52) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:97 red/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:111 SIREN/16000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:111 bitrate=16000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:112 G7221/16000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:112 bitrate=24000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:6 DVI4/16000 (21) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:4 G723/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:101 0-16 (15) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=encryption:optional (21) --- (11 headers 22 lines)--- Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: N06Ltbfx3pa9gc7P@192.168.0.245 Their Tag HZDuycGeqkyppaHF Our tag: as0f3e6eab Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag e5lHIHe8KAbQvGna Our tag: as0a6c366f Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 1516397444@192.168.0.101 Their Tag 1496440117 Our tag: as5e7a4f18 Jul 4 17:00:54 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.244 with 192.168.0.0 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 - INVITE (With RTP) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 Sending to 192.168.0.244 : 12714 (non-NAT) Jul 4 17:00:54 DEBUG[1742]: res_config_mysql.c:125 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sip WHERE name = '3005' Jul 4 17:00:54 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:7010 check_user_full: Setting NAT on RTP to 0 Reliably Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: ;tag=as43579da6 Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 1 INVITE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="1e28d709" Content-Length: 0 --- Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #27 Scheduling destruction of call '59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244' in 15000 ms Found user '3005' <-- SIP read from 192.168.0.244:4193: ACK sip:*553050@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: ;tag=as43579da6 Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 1 ACK User-Agent: RTC/1.2 Content-Length: 0 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: ACK sip:*553050@192.168.0.201 SIP/2.0 (37) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 (93) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: ;tag=as43579da6 (46) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 (55) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 1 ACK (11) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: RTC/1.2 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Content-Length: 0 (17) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 Their Tag 45a092f448fe4bc9891fb5a810bce9b8 Our tag: as43579da6 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #27 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244' of Response 1: Match Found <-- SIP read from 192.168.0.244:4193: INVITE sip:*553050@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 2 INVITE Contact: User-Agent: RTC/1.2 Proxy-Authorization: Digest username="3005", realm="asterisk", algorithm=md5, uri="sip:*553050@192.168.0.201", nonce="1e28d709", response="5e7dc4d7f7477d2e87ab2d5579974e97" Content-Type: application/sdp Content-Length: 525 v=0 o=- 0 0 IN IP4 192.168.0.244 s=session c=IN IP4 192.168.0.244 b=CT:1000 t=0 0 m=audio 37776 RTP/AVP 97 111 112 6 0 8 4 5 3 101 k=base64:FE0iEBy71TRgKYggVC+S8KWeamXk/5sk/OsUGK9lz7Y a=rtpmap:97 red/8000 a=rtpmap:111 SIREN/16000 a=fmtp:111 bitrate=16000 a=rtpmap:112 G7221/16000 a=fmtp:112 bitrate=24000 a=rtpmap:6 DVI4/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=encryption:optional Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: INVITE sip:*553050@192.168.0.201 SIP/2.0 (40) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 (93) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: (31) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 (55) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 2 INVITE (14) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Contact: (34) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: User-Agent: RTC/1.2 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Proxy-Authorization: Digest username="3005", realm="asterisk", algorithm=md5, uri="sip:*553050@192.168.0.201", nonce="1e28d709", response="5e7dc4d7f7477d2e87ab2d5579974e97" (172) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Type: application/sdp (29) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 525 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: v=0 (3) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: o=- 0 0 IN IP4 192.168.0.244 (28) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: s=session (9) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: c=IN IP4 192.168.0.244 (22) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: b=CT:1000 (9) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: t=0 0 (5) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: m=audio 37776 RTP/AVP 97 111 112 6 0 8 4 5 3 101 (48) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: k=base64:FE0iEBy71TRgKYggVC+S8KWeamXk/5sk/OsUGK9lz7Y (52) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:97 red/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:111 SIREN/16000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:111 bitrate=16000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:112 G7221/16000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:112 bitrate=24000 (24) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:6 DVI4/16000 (21) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:4 G723/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:5 DVI4/8000 (20) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=fmtp:101 0-16 (15) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: a=encryption:optional (21) --- (12 headers 22 lines)--- Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 Their Tag 45a092f448fe4bc9891fb5a810bce9b8 Our tag: as43579da6 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received INVITE (5) - Command in SIP INVITE Using INVITE request as basis request - 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 Sending to 192.168.0.244 : 12714 (non-NAT) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:7010 check_user_full: Setting NAT on RTP to 0 Found user '3005' Found RTP audio format 97 Found RTP audio format 111 Found RTP audio format 112 Found RTP audio format 6 Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 4 Found RTP audio format 5 Found RTP audio format 3 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.244:37776 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:3501 process_sdp: Peer audio RTP is at port 192.168.0.244:37776 Found description format red Found description format SIREN Found description format G7221 Found description format DVI4 Found description format PCMU Found description format PCMA Found description format G723 Found description format DVI4 Found description format GSM Found description format telephone-event Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x43f (g723|gsm|ulaw|alaw|g726|adpcm|ilbc)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:10320 handle_request_invite: Checking SIP call limits for device 3005 Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:2195 update_call_counter: Updating call counter for incoming call Looking for *553050 in from-sip (domain 192.168.0.201) Jul 4 17:00:54 DEBUG[1742]: chan_sip.c:6025 build_route: build_route: Contact hop: list_route: hop: Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 2 INVITE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Jul 4 17:00:54 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3005 Jul 4 17:00:54 DEBUG[1769]: pbx.c:1667 pbx_extension_helper: Launching 'ChanSpy' Jul 4 17:00:54 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3005 - state 2 (In use)  -- Executing ChanSpy("SIP/3005-f745", "SIP/3050|q") in new stack Jul 4 17:00:54 DEBUG[1770]: app_queue.c:502 changethread: Device 'SIP/3005' changed to state '2' (In use) Jul 4 17:00:54 DEBUG[1769]: channel.c:2475 set_format: Set channel SIP/3005-f745 to read format slin Jul 4 17:00:54 DEBUG[1769]: channel.c:2475 set_format: Set channel SIP/3005-f745 to write format slin Jul 4 17:00:54 DEBUG[1769]: chan_sip.c:2505 sip_answer: sip_answer(SIP/3005-f745) We're at 192.168.0.201 port 19172 Adding codec 0x4 (ulaw) to SDP Jul 4 17:00:54 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3005 Jul 4 17:00:54 DEBUG[1735]: channel.c:776 channel_find_locked: Avoiding initial deadlock for 'SIP/3005-f745' Adding codec 0x8 (alaw) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: ;tag=as1b122166 Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 2 INVITE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 1729 1729 IN IP4 192.168.0.201 s=session c=IN IP4 192.168.0.201 t=0 0 m=audio 19172 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 4 17:00:54 DEBUG[1769]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #29 Jul 4 17:00:55 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3005 - state 2 (In use) Jul 4 17:00:55 DEBUG[1771]: app_queue.c:502 changethread: Device 'SIP/3005' changed to state '2' (In use) <-- SIP read from 192.168.0.244:4193: ACK sip:*553050@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: ;tag=as1b122166 Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 2 ACK User-Agent: RTC/1.2 Content-Length: 0 Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: ACK sip:*553050@192.168.0.201 SIP/2.0 (37) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 (93) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: ;tag=as1b122166 (46) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 (55) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 2 ACK (11) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: RTC/1.2 (19) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Content-Length: 0 (17) Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 Their Tag 45a092f448fe4bc9891fb5a810bce9b8 Our tag: as1b122166 Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received ACK (6) - Command in SIP ACK Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #29 Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244' of Response 2: Match Found  == Spying on channel SIP/3050-2c24 Jul 4 17:00:55 NOTICE[1769]: app_chanspy.c:196 start_spying: Attaching SIP/3005-f745 to SIP/3050-2c24 Jul 4 17:00:55 DEBUG[1769]: channel.c:1007 ast_channel_spy_add: Spy ChanSpy added to channel SIP/3050-2c24 Jul 4 17:00:55 DEBUG[1769]: channel.c:1840 ast_settimeout: Scheduling timer at 160 sample intervals Jul 4 17:00:55 DEBUG[1761]: channel.c:1284 queue_frame_to_spies: Building translator from ulaw to SLINEAR for spies on channel SIP/3050-2c24 Jul 4 17:00:55 DEBUG[1761]: channel.c:1284 queue_frame_to_spies: Building translator from ulaw to SLINEAR for spies on channel SIP/3050-2c24 Jul 4 17:00:55 DEBUG[1769]: rtp.c:1341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.0.101:5060: Jul 4 17:00:55 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:00:55 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 60 bytes Jul 4 17:00:56 DEBUG[1769]: channel.c:2102 ast_read: Generator got voice, switching to phase locked mode Jul 4 17:00:56 DEBUG[1769]: channel.c:1840 ast_settimeout: Scheduling timer at 0 sample intervals Jul 4 17:00:58 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 88 bytes Jul 4 17:00:58 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes Jul 4 17:00:58 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:00:58 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:00:58 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:00:58 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 28 bytes Jul 4 17:01:00 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 80 bytes Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:00 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:01 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames <-- SIP read from 192.168.0.101:5060: Jul 4 17:01:01 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:01:02 DEBUG[1742]: chan_sip.c:1311 __sip_autodestruct: Auto destroying call 'N06Ltbfx3pa9gc7P@192.168.0.245' Destroying call 'N06Ltbfx3pa9gc7P@192.168.0.245' Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:02 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:03 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 80 bytes Jul 4 17:01:03 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:04 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 28 bytes Jul 4 17:01:05 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 88 bytes Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:05 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:06 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames <-- SIP read from 192.168.0.101:5060: Jul 4 17:01:07 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:01:08 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:08 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:09 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:09 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:09 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:09 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:09 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 28 bytes Jul 4 17:01:09 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 80 bytes Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:10 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1769]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' read queue too long, dropping frames <-- SIP read from 192.168.0.244:4193: BYE sip:*553050@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: ;tag=as1b122166 Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 3 BYE User-Agent: RTC/1.2 Content-Length: 0 Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: BYE sip:*553050@192.168.0.201 SIP/2.0 (37) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 (93) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: ;tag=as1b122166 (46) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 (55) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 3 BYE (11) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: RTC/1.2 (19) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Content-Length: 0 (17) Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 4 17:01:11 DEBUG[1761]: channel.c:1355 queue_frame_to_spies: Spy 'ChanSpy' on channel 'SIP/3050-2c24' write queue too long, dropping frames Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 Their Tag 45a092f448fe4bc9891fb5a810bce9b8 Our tag: as1b122166 Jul 4 17:01:11 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.0.244 : 12714 (non-NAT) Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: "Roberto" ;tag=45a092f448fe4bc9891fb5a810bce9b8;epid=af8fc74f60 To: ;tag=as1b122166 Call-ID: 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244 CSeq: 3 BYE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Jul 4 17:01:11 DEBUG[1769]: channel.c:1840 ast_settimeout: Scheduling timer at 0 sample intervals Jul 4 17:01:11 DEBUG[1769]: channel.c:1061 ast_channel_spy_remove: Spy ChanSpy removed from channel SIP/3050-2c24  == Done Spying on channel SIP/3050-2c24 Jul 4 17:01:11 DEBUG[1769]: channel.c:2475 set_format: Set channel SIP/3005-f745 to read format ulaw Jul 4 17:01:11 DEBUG[1769]: channel.c:2475 set_format: Set channel SIP/3005-f745 to write format ulaw Jul 4 17:01:11 DEBUG[1769]: pbx.c:2306 __ast_pbx_run: Spawn extension (from-sip,*553050,1) exited non-zero on 'SIP/3005-f745' Jul 4 17:01:11 DEBUG[1769]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Jul 4 17:01:11 DEBUG[1769]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-07-04 17:00:54','\"Roberto\" <3005>','3005','*553050','from-sip', 'SIP/3005-f745','','ChanSpy','SIP/3050|q',17,16,'ANSWERED',3,'','1152043254.2','') Jul 4 17:01:11 DEBUG[1769]: channel.c:1452 ast_hangup: Hanging up channel 'SIP/3005-f745' Jul 4 17:01:11 DEBUG[1769]: chan_sip.c:2401 sip_hangup: Hangup call SIP/3005-f745, SIP callid 59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244) Jul 4 17:01:11 DEBUG[1769]: chan_sip.c:2409 sip_hangup: update_call_counter(3005) - decrement call limit counter Jul 4 17:01:11 DEBUG[1769]: chan_sip.c:2195 update_call_counter: Updating call counter for incoming call Jul 4 17:01:11 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3005 Jul 4 17:01:11 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3005 - state 1 (Not in use) Jul 4 17:01:11 DEBUG[1787]: app_queue.c:502 changethread: Device 'SIP/3005' changed to state '1' (Not in use) Destroying call '59babc9b44ee4b75ae38decb1cd5f2c8@192.168.0.244' Jul 4 17:01:13 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 84 bytes <-- SIP read from 192.168.0.101:5060: Jul 4 17:01:13 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:01:13 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 80 bytes Jul 4 17:01:17 DEBUG[1761]: rtp.c:410 ast_rtcp_read: Got RTCP report of 40 bytes <-- SIP read from 192.168.0.101:5060: BYE sip:3002@192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK61150992 From: "anonymous" ;tag=1496440117 To: ;tag=as5e7a4f18 Call-ID: 1516397444@192.168.0.101 CSeq: 1001 BYE max-forwards: 70 user-agent: UTSTARCOM F1000/Device ID-0007ba252d95 Content-Length: 0 Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: BYE sip:3002@192.168.0.201 SIP/2.0 (34) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK61150992 (64) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "anonymous" ;tag=1496440117 (57) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: ;tag=as5e7a4f18 (43) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 1516397444@192.168.0.101 (33) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: CSeq: 1001 BYE (14) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: max-forwards: 70 (16) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: user-agent: UTSTARCOM F1000/Device ID-0007ba252d95 (50) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Content-Length: 0 (17) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3149 find_call: = No match Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag e5lHIHe8KAbQvGna Our tag: as0a6c366f Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 1516397444@192.168.0.101 Their Tag 1496440117 Our tag: as5e7a4f18 Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.0.101 : 5060 (non-NAT) Transmitting (no NAT) to 192.168.0.101:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.101:5060;rport;branch=z9hG4bK61150992;received=192.168.0.101 From: "anonymous" ;tag=1496440117 To: ;tag=as5e7a4f18 Call-ID: 1516397444@192.168.0.101 CSeq: 1001 BYE User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Jul 4 17:01:17 DEBUG[1761]: channel.c:3383 ast_generic_bridge: Didn't get a frame from channel: SIP/3050-2c24 Jul 4 17:01:17 DEBUG[1761]: channel.c:3658 ast_channel_bridge: Bridge stops bridging channels SIP/3050-2c24 and SIP/3002-e829 Jul 4 17:01:17 DEBUG[1761]: channel.c:1452 ast_hangup: Hanging up channel 'SIP/3002-e829' Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:2401 sip_hangup: Hangup call SIP/3002-e829, SIP callid 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201) Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:2409 sip_hangup: update_call_counter(3002) - decrement call limit counter Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:2195 update_call_counter: Updating call counter for outgoing call set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.245, port 5060 Reliably Transmitting (no NAT) to 192.168.0.245:5060: BYE sip:3002@192.168.0.245:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK1ee88098;rport From: "anonymous" ;tag=as0a6c366f To: ;tag=e5lHIHe8KAbQvGna Contact: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 CSeq: 103 BYE User-Agent: Dialtech IP PBX Max-Forwards: 70 Content-Length: 0 --- Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #30 Jul 4 17:01:17 DEBUG[1761]: app_dial.c:1586 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jul 4 17:01:17 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3002 Jul 4 17:01:17 DEBUG[1761]: pbx.c:2306 __ast_pbx_run: Spawn extension (from-sip,3002,1) exited non-zero on 'SIP/3050-2c24' Jul 4 17:01:17 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3002 - state 1 (Not in use) Jul 4 17:01:17 DEBUG[1788]: app_queue.c:502 changethread: Device 'SIP/3002' changed to state '1' (Not in use) Jul 4 17:01:17 DEBUG[1761]: cdr_addon_mysql.c:206 mysql_log: cdr_mysql: inserting a CDR record. Jul 4 17:01:17 DEBUG[1761]: cdr_addon_mysql.c:222 mysql_log: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-07-04 17:00:42','\"anonymous\" <3050>','3050','3002','from-sip', 'SIP/3050-2c24','SIP/3002-e829','Dial','SIP/3002|60|rtTwW',35,34,'ANSWERED',3,'','1152043242.0','') Jul 4 17:01:17 DEBUG[1761]: channel.c:1452 ast_hangup: Hanging up channel 'SIP/3050-2c24' Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:2401 sip_hangup: Hangup call SIP/3050-2c24, SIP callid 1516397444@192.168.0.101) Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:2409 sip_hangup: update_call_counter(3050) - decrement call limit counter Jul 4 17:01:17 DEBUG[1761]: chan_sip.c:2195 update_call_counter: Updating call counter for incoming call Jul 4 17:01:17 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3050 Jul 4 17:01:17 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3050 - state 1 (Not in use) Jul 4 17:01:17 DEBUG[1789]: app_queue.c:502 changethread: Device 'SIP/3050' changed to state '1' (Not in use) <-- SIP read from 192.168.0.245:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK1ee88098;rport Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 CSeq: 103 BYE From: "anonymous" ;tag=as0a6c366f To: ;tag=e5lHIHe8KAbQvGna Contact: Content-Length: 0 Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 200 OK (14) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK1ee88098;rport (64) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Call-ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 (55) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: CSeq: 103 BYE (13) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: From: "anonymous" ;tag=as0a6c366f (60) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: To: ;tag=e5lHIHe8KAbQvGna (54) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: Contact: (38) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 7ef561b14298c22b2b5b1b3302f10448@192.168.0.201 Their Tag e5lHIHe8KAbQvGna Our tag: as0a6c366f Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #30 Jul 4 17:01:17 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '7ef561b14298c22b2b5b1b3302f10448@192.168.0.201' of Request 103: Match Found Destroying call '7ef561b14298c22b2b5b1b3302f10448@192.168.0.201' Destroying call '1516397444@192.168.0.101' <-- SIP read from 192.168.0.244:4193: REGISTER sip:192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 To: Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 CSeq: 43 REGISTER Contact: ;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER" User-Agent: RTC/1.2.4949 Event: registration Allow-Events: presence Content-Length: 0 Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: REGISTER sip:192.168.0.201 SIP/2.0 (34) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 (83) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: (28) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 (55) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 43 REGISTER (17) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Contact: ;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER" (119) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: User-Agent: RTC/1.2.4949 (24) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Event: registration (19) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Allow-Events: presence (22) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 0 (17) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) --- (12 headers 0 lines)--- Jul 4 17:01:18 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.244 with 192.168.0.0 Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 - REGISTER (No RTP) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.0.244 : 12714 (non-NAT) Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 To: Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 CSeq: 43 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 To: ;tag=as1e5998e5 Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 CSeq: 43 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: WWW-Authenticate: Digest realm="asterisk", nonce="6508b1fd" Content-Length: 0 --- Scheduling destruction of call 'c4e58c2cf132461fa13127dd685d5dab@192.168.0.244' in 15000 ms <-- SIP read from 192.168.0.244:4193: REGISTER sip:192.168.0.201 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.244:12714 Max-Forwards: 70 From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 To: Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 CSeq: 44 REGISTER Contact: ;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER" User-Agent: RTC/1.2.4949 Authorization: Digest username="3005", realm="asterisk", algorithm=md5, uri="sip:192.168.0.201", nonce="6508b1fd", response="abd1705770f19eab69cd4376a2a63f1a" Event: registration Allow-Events: presence Content-Length: 0 Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: REGISTER sip:192.168.0.201 SIP/2.0 (34) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.244:12714 (36) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: Max-Forwards: 70 (16) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 (83) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: To: (28) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 (55) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 44 REGISTER (17) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Contact: ;methods="INVITE, MESSAGE, INFO, SUBSCRIBE, OPTIONS, BYE, CANCEL, NOTIFY, ACK, REFER" (119) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: User-Agent: RTC/1.2.4949 (24) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Authorization: Digest username="3005", realm="asterisk", algorithm=md5, uri="sip:192.168.0.201", nonce="6508b1fd", response="abd1705770f19eab69cd4376a2a63f1a" (158) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Event: registration (19) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Allow-Events: presence (22) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: Content-Length: 0 (17) Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 13: (0) --- (13 headers 0 lines)--- Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 Their Tag b88e8aa8e9dd48aaa7b3224457161b4c Our tag: as1e5998e5 Jul 4 17:01:18 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Using latest REGISTER request as basis request Sending to 192.168.0.244 : 12714 (non-NAT) Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 To: Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 CSeq: 44 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Contact: Content-Length: 0 --- Jul 4 17:01:18 DEBUG[1742]: res_config_mysql.c:321 update_mysql: MySQL RealTime: Update SQL: UPDATE sip SET ipaddr = '192.168.0.244', port = '12714', regseconds = '1152043398', username = '', fullcontact = 'sip:192.168.0.244:12714' WHERE name = '3005' Jul 4 17:01:18 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:01:18 DEBUG[1742]: res_config_mysql.c:341 update_mysql: MySQL RealTime: Updated 1 rows on table: sip Transmitting (no NAT) to 192.168.0.244:12714: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.244:12714;received=192.168.0.244 From: ;tag=b88e8aa8e9dd48aaa7b3224457161b4c;epid=af8fc74f60 To: ;tag=as1e5998e5 Call-ID: c4e58c2cf132461fa13127dd685d5dab@192.168.0.244 CSeq: 44 REGISTER User-Agent: Dialtech IP PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Max-Forwards: 70 Expires: 120 Contact: ;expires=120 Date: Tue, 04 Jul 2006 20:01:18 GMT Content-Length: 0 --- Scheduling destruction of call 'c4e58c2cf132461fa13127dd685d5dab@192.168.0.244' in 15000 ms Jul 4 17:01:18 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3005 Jul 4 17:01:18 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3005 - state 1 (Not in use) Jul 4 17:01:18 DEBUG[1790]: app_queue.c:502 changethread: Device 'SIP/3005' changed to state '1' (Not in use) <-- SIP read from 192.168.0.101:5060: Jul 4 17:01:19 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive ---  -- Remote UNIX connection Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP) Jul 4 17:01:23 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.244 with 192.168.0.0 Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: NOTIFY sip:192.168.0.244:12714 SIP/2.0 (38) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7a39d3e4;rport (64) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as0bc3aa8a (60) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: (29) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Contact: (37) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: Call-ID: 2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201 (55) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: CSeq: 102 NOTIFY (16) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: User-Agent: Dialtech IP PBX (27) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: Max-Forwards: 70 (16) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 9: Event: message-summary (22) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 10: Content-Type: application/simple-message-summary (48) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 11: Content-Length: 80 (18) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 12: (0) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Messages-Waiting: no (20) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Message-Account: sip:asterisk@ (30) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3349 parse_request: Line: Voice-Message: 0/0 (0/0) (24) 12 headers, 3 lines Reliably Transmitting (no NAT) to 192.168.0.244:12714: NOTIFY sip:192.168.0.244:12714 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7a39d3e4;rport From: "asterisk" ;tag=as0bc3aa8a To: Contact: Call-ID: 2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201 CSeq: 102 NOTIFY User-Agent: Dialtech IP PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 80 Messages-Waiting: no Message-Account: sip:asterisk@ Voice-Message: 0/0 (0/0) --- Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:1284 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #34 Scheduling destruction of call '2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201' in 15000 ms <-- SIP read from 192.168.0.244:4193: SIP/2.0 481 Call Leg/Transaction Does Not Exist Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7a39d3e4;rport From: "asterisk" ;tag=as0bc3aa8a To: ;tag=4dfc5bb8313f4436b3f0855fa81e3992 Call-ID: 2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201 CSeq: 102 NOTIFY User-Agent: RTC/1.2 Content-Length: 0 Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: SIP/2.0 481 Call Leg/Transaction Does Not Exist (47) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.201:5060;branch=z9hG4bK7a39d3e4;rport (64) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 2: From: "asterisk" ;tag=as0bc3aa8a (60) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 3: To: ;tag=4dfc5bb8313f4436b3f0855fa81e3992 (66) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 4: Call-ID: 2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201 (55) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 5: CSeq: 102 NOTIFY (16) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 6: User-Agent: RTC/1.2 (19) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 7: Content-Length: 0 (17) Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: 2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201 Their Tag Our tag: as0bc3aa8a Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:1378 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #34 Jul 4 17:01:23 DEBUG[1742]: chan_sip.c:1389 __sip_ack: Stopping retransmission on '2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201' of Request 102: Match Found  -- Got SIP response 481 "Call Leg/Transaction Does Not Exist" back from 192.168.0.244 Destroying call '2ad3304e3a0a5ecb720aeec50ead31a0@192.168.0.201' <-- SIP read from 192.168.0.101:5060: Jul 4 17:01:25 DEBUG[1742]: chan_sip.c:3317 parse_request: Header 0: (0) --- (0 headers 0 lines) Nat keepalive --- Jul 4 17:01:33 DEBUG[1742]: chan_sip.c:1311 __sip_autodestruct: Auto destroying call 'c4e58c2cf132461fa13127dd685d5dab@192.168.0.244'  -- Remote UNIX connection disconnected Jul 4 17:01:47 DEBUG[1742]: acl.c:211 ast_apply_ha: ##### Testing 192.168.0.245 with 192.168.0.0 Jul 4 17:01:47 DEBUG[1742]: chan_sip.c:3101 sip_alloc: Allocating new SIP dialog for N06Ltbfx3pa9gc7P@192.168.0.245 - REGISTER (No RTP) Jul 4 17:01:47 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Jul 4 17:01:47 DEBUG[1742]: chan_sip.c:3149 find_call: = Found Their Call ID: N06Ltbfx3pa9gc7P@192.168.0.245 Their Tag chneDTjuGtJdGHMH Our tag: as62f1acdd Jul 4 17:01:47 DEBUG[1742]: chan_sip.c:10909 handle_request: **** Received REGISTER (2) - Command in SIP REGISTER Jul 4 17:01:48 DEBUG[1742]: res_config_mysql.c:321 update_mysql: MySQL RealTime: Update SQL: UPDATE sip SET ipaddr = '192.168.0.245', port = '5060', regseconds = '1152043368', username = '3002', fullcontact = 'sip:3002@192.168.0.245:5060' WHERE name = '3002' Jul 4 17:01:48 DEBUG[1742]: res_config_mysql.c:636 mysql_reconnect: MySQL RealTime: Everything is fine. Jul 4 17:01:48 DEBUG[1742]: res_config_mysql.c:341 update_mysql: MySQL RealTime: Updated 1 rows on table: sip Jul 4 17:01:48 DEBUG[1735]: chan_sip.c:11431 sip_devicestate: Checking device state for peer 3002 Jul 4 17:01:48 DEBUG[1735]: devicestate.c:187 do_state_change: Changing state for SIP/3002 - state 1 (Not in use) Jul 4 17:01:48 DEBUG[1794]: app_queue.c:502 changethread: Device 'SIP/3002' changed to state '1' (Not in use)  -- Remote UNIX connection Beginning dip shutdown.... Executing last minute cleanups  == Destroying musiconhold processes DIP cleanly ending (0).