Script started on Sun Nov 21 06:41:26 2004 minitokyo:~ # asterisk -vvvvvdc Parsing /etc/asterisk/asterisk.conf Parsing /etc/asterisk/extconfig.conf Asterisk CVS-HEAD-11/21/04-04:44:06, Copyright (C) 1999-2004 Digium. Written by Mark Spencer ========================================================================= Asterisk Event Logger Started /var/log/asterisk/event_log  == 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 MailboxStatus  == Manager registered action Command  == Manager registered action ExtensionState  == Manager registered action AbsoluteTimeout  == Manager registered action MailboxCount  == Manager registered action ListCommands Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/manager.conf Asterisk Management interface listening on port 5038 Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/rtp.conf  == RTP Allocating from port range 10000 -> 20000 Asterisk 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'  [Hangup]  == Registered application 'Hangup'  [NoOp]  == Registered application 'NoOp'  [Prefix]  == Registered application 'Prefix'  [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'  [SetVar]  == Registered application 'SetVar'  [ImportVar]  == Registered application 'ImportVar'  [StripMSD]  == Registered application 'StripMSD'  [Suffix]  == Registered application 'Suffix'  [Wait]  == Registered application 'Wait'  [WaitExten]  == Registered application 'WaitExten' Asterisk Dynamic Loader Starting: Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf  [chan_h323.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (The NuFone Network's Open H.323 Channel Driver) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/h323.conf == Creating H.323 Endpoint  == Setting default context to voip-h323 == Adding alias "conference-b" to endpoint == Adding E.164 "4489" to endpoint Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'H323' (The NuFone Network's Open H.323 Channel Driver) == H.323 listener started == Using GnuH323GK@tca10156v.corp.tdktca.com as our Gatekeeper.  [chan_modem.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Generic Voice Modem Driver) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modem.conf  == Loading modem driver chan_modem_aopen.soNov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (A/Open (Rockwell Chipset) ITU-2 VoiceModem Driver) Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Modem' (Generic Voice Modem Channel Driver)  [res_musiconhold.so] => (Music On Hold Resource) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/musiconhold.conf Nov 21 06:41:32 WARNING[13172]: res_musiconhold.c:564 moh_register: Unable to open pseudo channel for timing... Sound may be choppy.  == Registered application 'MusicOnHold'  == Registered application 'WaitMusicOnHold'  == Registered application 'SetMusicOnHold'  [res_indications.so] => (Indications Configuration) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/indications.conf  -- Registered indication country 'us'  -- Registered indication country 'au'  -- Registered indication country 'fr'  -- Registered indication country 'de'  -- Registered indication country 'nl'  -- Registered indication country 'uk'  -- Registered indication country 'fi'  -- Registered indication country 'no'  -- Registered indication country 'br'  -- Registered indication country 'za'  -- Registered indication country 'it'  -- Setting default indication country to 'us'  == Registered application 'Playtones'  == Registered application 'StopPlaytones'  [res_features.so] => (Call Parking Resource) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/features.conf Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'parkedcalls' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '700' priority 1 to parkedcalls  == Registered application 'ParkedCall'  == Registered application 'Park'  == Manager registered action ParkedCalls  [res_agi.so] => (Asterisk Gateway Interface (AGI))  == Registered application 'DeadAGI'  == Registered application 'EAGI'  == Registered application 'AGI'  [res_crypto.so] => (Cryptographic Digital Signatures)  -- Loaded PUBLIC key 'iaxtel' Nov 21 06:41:32 DEBUG[13172]: res_crypto.c:243 try_load_key: Key 'iaxtel' loaded OK  -- Loaded PUBLIC key 'freeworlddialup' Nov 21 06:41:32 DEBUG[13172]: res_crypto.c:243 try_load_key: Key 'freeworlddialup' loaded OK  [res_adsi.so] => (ADSI Resource) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/adsi.conf  [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  [chan_modem_i4l.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (ISDN4Linux Emulated Modem Driver)  [chan_mgcp.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Media Gateway Control Protocol (MGCP)) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/mgcp.conf  == MGCP Listening on 0.0.0.0:2727  == Using TOS bits 0 Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'MGCP' (Media Gateway Control Protocol (MGCP))  [chan_zap.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Zapata Telephony) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/zapata.conf  -- Automatically generated pseudo channel Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Zap' (Zapata Telephony Driver)  == Registered application 'CallingPres'  == Manager registered action ZapTransfer  == Manager registered action ZapHangup  == Manager registered action ZapDialOffhook  == Manager registered action ZapDNDon  == Manager registered action ZapDNDoff  == Manager registered action ZapShowChannels  [chan_local.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Local Proxy Channel) Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Local' (Local Proxy Channel Driver)  [skipping chan_alsa.so]  [chan_iax2.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Inter Asterisk eXchange (Ver 2)) Nov 21 06:41:32 WARNING[13172]: chan_iax2.c:7500 load_module: Unable to open IAX timing interface: No such device or address  == Manager registered action IAXpeers Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/iax.conf Nov 21 06:41:32 DEBUG[13172]: acl.c:164 ast_append_ha: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Nov 21 06:41:32 DEBUG[13172]: acl.c:164 ast_append_ha: 216.207.245.47/255.255.255.255/255.255.255.255 appended to acl for peer  -- Seeding '4307' at 163.49.133.214:4569 for 60 Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'IAX2' (Inter Asterisk eXchange Driver (Ver 2))  == Using TOS bits 16  == IAX Ready and Listening on 0.0.0.0 port 4569  == Loaded firmware 'iaxy.bin' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/iaxprov.conf  -- Loaded provisioning template 'default'  [chan_agent.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Agent Proxy Channel) Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Agent' (Call Agent Proxy Channel)  == Registered application 'AgentLogin'  == Registered application 'AgentCallbackLogin'  == Registered application 'AgentMonitorOutgoing' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/agents.conf  [chan_modem_bestdata.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (BestData (Conexant V.90 Chipset) VoiceModem Driver)  [chan_phone.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Linux Telephony API Support) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/phone.conf Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Phone' (Standard Linux Telephony API Driver)  [chan_skinny.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Skinny Client Control Protocol (Skinny)) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/skinny.conf Nov 21 06:41:32 WARNING[13172]: chan_skinny.c:2602 reload_config: Unable to get our IP address, Skinny disabled Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Skinny' (Skinny Client Control Protocol (Skinny))  [chan_features.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Feature Proxy Channel) Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'Feature' (Feature Proxy Channel Driver)  [skipping chan_oss.so]  [chan_sip.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Session Initiation Protocol (SIP)) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/sip.conf  == SIP Listening on 0.0.0.0:5060  == Using TOS bits 0 Nov 21 06:41:32 DEBUG[13172]: channel.c:199 ast_channel_register_ex: Registered handler for 'SIP' (Session Initiation Protocol (SIP))  == Registered application 'SIPDtmfMode'  [pbx_dundi.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Distributed Universal Number Discovery (DUNDi)) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/dundi.conf Nov 21 06:41:32 DEBUG[13172]: pbx_dundi.c:401 reset_global_eid: Seeding global EID '00:0b:cd:00:48:e3' from 'eth0'  == Using TOS bits 0  == DUNDi Ready and Listening on 0.0.0.0 port 4520  == Registered application 'DUNDiLookup'  [pbx_spool.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Outgoing Spool Support)  [pbx_loopback.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Loopback Switch)  [pbx_config.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Text Extension Configuration) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/extensions.conf  -- Setting global variable 'CONSOLE' to 'Console/dsp'  -- Setting global variable 'IAXINFO' to 'guest'  -- Setting global variable 'TRUNKMSD' to '1' Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'iaxtel700' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_91700NXXXXXX' priority 1 to iaxtel700 Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'iaxprovider' Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'trunkint' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_9011.' priority 1 to trunkint Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_9011.' priority 2 to trunkint Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'trunkld' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_91NXXNXXXXXX' priority 1 to trunkld Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_91NXXNXXXXXX' priority 2 to trunkld Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'trunklocal' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_9NXXXXXX' priority 1 to trunklocal Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_9NXXXXXX' priority 2 to trunklocal Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'trunktollfree' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_91800NXXXXXX' priority 1 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_91800NXXXXXX' priority 2 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_91888NXXXXXX' priority 1 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_91888NXXXXXX' priority 2 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '_91877NXXXXXX' priority 1 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_91877NXXXXXX' priority 2 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '_91866NXXXXXX' priority 1 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_91866NXXXXXX' priority 2 to trunktollfree Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'international'  -- Including context 'longdistance' in context 'international'  -- Including context 'trunkint' in context 'international' Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'longdistance'  -- Including context 'local' in context 'longdistance'  -- Including context 'trunkld' in context 'longdistance' Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'local'  -- Including context 'default' in context 'local'  -- Including context 'parkedcalls' in context 'local'  -- Including context 'trunklocal' in context 'local'  -- Including context 'iaxtel700' in context 'local'  -- Including context 'trunktollfree' in context 'local'  -- Including context 'iaxprovider' in context 'local' Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'macro-stdexten' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension 's' priority 1 to macro-stdexten Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 2 to macro-stdexten Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 3 to macro-stdexten Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 102 to macro-stdexten Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 103 to macro-stdexten Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'default'  -- Including context 'voip-h323' in context 'default' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '_781XXXX' priority 1 to default Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '_781XXXX' priority 2 to default Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '64307' priority 1 to default Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'tca-meetme' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension 's' priority 1 to tca-meetme Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 2 to tca-meetme Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 3 to tca-meetme Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 4 to tca-meetme Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension 't' priority 1 to tca-meetme  -- Including context 'bridge-defns' in context 'tca-meetme' Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'voip-h323' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '4489' priority 1 to voip-h323 Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension 'i' priority 1 to voip-h323 Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'macro-tca-bridge' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension 's' priority 1 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 2 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 3 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 4 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 5 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 6 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 's' priority 7 to macro-tca-bridge Nov 21 06:41:32 DEBUG[13172]: pbx.c:3090 ast_context_create: Registered context 'bridge-defns' Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension '1' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '1' priority 2 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '1' priority 3 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension '1' priority 4 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4172 ast_add_extension2: Added extension 'i' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 'i' priority 2 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4138 ast_add_extension2: Added extension 'i' priority 3 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4360' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4307' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2135' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2100' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4302' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4300' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4311' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '6616' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2107' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '7208' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '7373' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4379' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4367' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4314' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4467' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4474' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4475' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '6620' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '6512' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '3118' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '7203' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '5231' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2189' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2183' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2182' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2191' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2185' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2180' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '2184' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4397' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '5222' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4322' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '7330' priority 1 to bridge-defns Nov 21 06:41:32 DEBUG[13172]: pbx.c:4157 ast_add_extension2: Added extension '4512' priority 1 to bridge-defns  [app_sms.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (SMS/PSTN handler)  == Registered application 'SMS'  [app_hasnewvoicemail.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Indicator for whether a voice mailbox has messages in a given folder.[)  == Registered application 'HasVoicemail'  == Registered application 'HasNewVoicemail'  [format_wav_gsm.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Microsoft WAV format (Proprietary GSM))  == Registered file format wav49, extension(s) WAV|wav49  [app_url.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Send URL Applications)  == Registered application 'SendURL'  [app_test.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Interface Test Application)  == Registered application 'TestClient'  == Registered application 'TestServer'  [app_eval.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Reevaluates strings)  == Registered application 'Eval'  [app_sendtext.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Send Text Applications)  == Registered application 'SendText'  [app_exec.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Executes applications)  == Registered application 'Exec'  [app_txtcidname.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (TXTCIDName)  == Registered application 'TXTCIDName' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/enum.conf  [cdr_manager.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Asterisk Call Manager CDR Backend) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/cdr_manager.conf  [app_directory.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Extension Directory)  == Registered application 'Directory'  [app_playback.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Trivial Playback Application)  == Registered application 'Playback'  [codec_adpcm.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Adaptive Differential PCM Coder/Decoder)  == Registered translator 'adpcmtolin' from format ADPCM to SLINR, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix  == Registered translator 'lintoadpcm' from format SLINR to ADPCM, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix  [app_groupcount.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Group Management Routines)  == Registered application 'GetGroupCount'  == Registered application 'SetGroup'  == Registered application 'CheckGroup'  == Registered application 'GetGroupMatchCount'  [app_adsiprog.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Asterisk ADSI Programming Application)  == Registered application 'ADSIProg'  [app_chanisavail.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Check if channel is available)  == Registered application 'ChanIsAvail'  [app_softhangup.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Hangs up the requested channel)  == Registered application 'SoftHangup'  [codec_lpc10.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (LPC10 2.4kbps (signed linear) Voice Coder)  == Registered translator 'lpc10tolin' from format LPC10 to SLINR, cost 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  == Registered translator 'lintolpc10' from format SLINR to LPC10, cost 5 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  [app_setcidname.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Set CallerID Name)  == Registered application 'SetCIDName'  [format_g726.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (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  [format_g729.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw G729 data)  == Registered file format g729, extension(s) g729  [app_userevent.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Custom User Event Application)  == Registered application 'UserEvent'  [codec_gsm.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (GSM/PCM16 (signed linear) Codec Translator)  == Registered translator 'gsmtolin' from format GSM to SLINR, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  == Registered translator 'lintogsm' from format SLINR to GSM, cost 3 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  [app_authenticate.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Authentication Application)  == Registered application 'Authenticate'  [format_pcm_alaw.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw aLaw 8khz PCM Audio support)  == Registered file format alaw, extension(s) alaw|al  [format_ilbc.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw iLBC data)  == Registered file format iLBC, extension(s) ilbc  [format_h263.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw h263 data)  == Registered file format h263, extension(s) h263  [app_forkcdr.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Fork The CDR into 2 seperate entities.)  == Registered application 'ForkCDR'  [app_ices.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Encode and Stream via icecast and ices)  == Registered application 'ICES'  [skipping chan_alsa.so]  [app_nbscat.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Silly NBS Stream Application)  == Registered application 'NBScat'  [codec_a_mu.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (A-law and Mulaw direct Coder/Decoder)  == Registered translator 'alawtoulaw' from format ALAW to ULAW, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  == Registered translator 'ulawtoalaw' from format ULAW to ALAW, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  [app_system.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Generic System() application)  == Registered application 'TrySystem'  == Registered application 'System'  [app_record.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Trivial Record Application)  == Registered application 'Record'  [app_milliwatt.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Digital Milliwatt (mu-law) Test Application)  == Registered application 'Milliwatt'  [app_parkandannounce.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Call Parking and Announce Application)  == Registered application 'ParkAndAnnounce'  [app_sayunixtime.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Say time)  == Registered application 'SayUnixTime'  == Registered application 'DateTime'  [app_dumpchan.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Dump Info About The Calling Channel)  == Registered application 'DumpChan'  [cdr_pgsql.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (PostgreSQL CDR Backend) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/cdr_pgsql.conf  [app_zapscan.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Scan Zap channels application)  == Registered application 'ZapScan'  [app_macro.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Extension Macros)  == Registered application 'Macro'  [app_random.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Random goto)  == Registered application 'Random'  [codec_ulaw.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Mu-law Coder/Decoder)  == Registered translator 'ulawtolin' from format ULAW to SLINR, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  == Registered translator 'lintoulaw' from format SLINR to ULAW, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from G723 to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2  [app_zapras.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Zap RAS Application)  == Registered application 'ZapRAS'  [app_controlplayback.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Control Playback Application)  == Registered application 'ControlPlayback'  [format_jpeg.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (JPEG (Joint Picture Experts Group) Image Format)  == Registered format 'jpg' (JPEG (Joint Picture Experts Group))  [codec_alaw.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (A-law Coder/Decoder)  == Registered translator 'alawtolin' from format ALAW to SLINR, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from G723 to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2  == Registered translator 'lintoalaw' from format SLINR to ALAW, cost 1 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  [app_transfer.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Transfer)  == Registered application 'Transfer'  [cdr_csv.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Comma Separated Values CDR Backend)  [app_voicemail.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Comedian Mail (Voicemail System))  == Registered application 'VoiceMail'  == Registered application 'VoiceMailMain'  == Registered application 'MailboxExists'  == Registered application 'VMAuthenticate' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/voicemail.conf Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4385 load_config: VM Review Option disabled globally Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4392 load_config: VM Operator break disabled globally Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4399 load_config: VM CID Info before msg disabled globally Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4406 load_config: Send Voicemail msg disabled globally Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4413 load_config: ENVELOPE before msg enabled globally Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4420 load_config: Duration info before msg enabled globally Nov 21 06:41:32 DEBUG[13172]: app_voicemail.c:4436 load_config: We are not going to skip to the next msg after save/delete  [app_verbose.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Send verbose output)  == Registered application 'Verbose'  [app_setcdruserfield.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (CDR user field apps)  == Registered application 'SetCDRUserField'  == Registered application 'AppendCDRUserField'  == Manager registered action SetCDRUserField  [codec_g726.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (ITU G.726-32kbps G726 Transcoder)  == Registered translator 'g726tolin' from format G726 to SLINR, cost 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from ULAW to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  == Registered translator 'lintog726' from format SLINR to G726, cost 3 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from G723 to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to ULAW, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from ULAW to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6  [app_lookupblacklist.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Look up Caller*ID name/number from blacklist database)  == Registered application 'LookupBlacklist'  [app_zapbarge.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Barge in on Zap channel application)  == Registered application 'ZapBarge'  [app_getcpeid.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Get ADSI CPE ID)  == Registered application 'GetCPEID'  [app_enumlookup.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (ENUM Lookup)  == Registered application 'EnumLookup' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/enum.conf  [codec_ilbc.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (iLBC/PCM16 (signed linear) Codec Translator)  == Registered translator 'ilbctolin' from format ILBC to SLINR, cost 3 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from G723 to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to ULAW, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from ULAW to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 8 cost path from UNKN to UNKN, via 6  == Registered translator 'lintoilbc' from format SLINR to ILBC, cost 17 Nov 21 06:41:32 DEBUG[13172]: translate.c:277 rebuild_matrix: Reseting translation matrix Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from G723 to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 18 cost path from G723 to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from GSM to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 18 cost path from GSM to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to ULAW, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 19 cost path from UNKN to UNKN, via 2 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 18 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from ULAW to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 7 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 19 cost path from ULAW to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 2 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 18 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 5 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 3 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 19 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to G723, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to GSM, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 6 cost path from UNKN to ULAW, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 4 cost path from UNKN to UNKN, via 6 Nov 21 06:41:32 DEBUG[13172]: translate.c:315 rebuild_matrix: Discovered 8 cost path from UNKN to UNKN, via 6  [app_read.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Read Variable Application)  == Registered application 'Read'  [app_alarmreceiver.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Alarm Receiver for Asterisk) Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/alarmreceiver.conf  == Registered application 'AlarmReceiver'  [format_gsm.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw GSM data)  == Registered file format gsm, extension(s) gsm  [app_dial.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Dialing Application)  == Registered application 'Dial'  [app_striplsd.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Strip trailing digits)  == Registered application 'StripLSD'  [app_disa.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (DISA (Direct Inward System Access) Application)  == Registered application 'DISA'  [app_realtime.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Realtime Data Lookup/Rewrite)  == Registered application 'RealTimeUpdate'  == Registered application 'RealTime'  [app_cdr.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Make sure asterisk doesn't save CDR for a certain call)  == Registered application 'NoCDR'  [app_image.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Image Transmission Application)  == Registered application 'SendImage'  [app_cut.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Cuts up variables)  == Registered application 'Cut'  [app_festival.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Simple Festival Interface)  == Registered application 'Festival'  [app_meetme.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (MeetMe conference bridge)  == Registered application 'MeetMeAdmin'  == Registered application 'MeetMeCount'  == Registered application 'MeetMe'  [app_echo.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Simple Echo Application)  == Registered application 'Echo'  [format_pcm.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw uLaw 8khz Audio support (PCM))  == Registered file format pcm, extension(s) pcm|ulaw|ul|mu  [app_privacy.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Require phone number to be entered, if no CallerID sent)  == Registered application 'PrivacyManager'  [app_flash.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Flash zap trunk application)  == Registered application 'Flash'  [skipping app_intercom.so]  [app_setcallerid.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Set CallerID Application)  == Registered application 'SetCallerPres'  == Registered application 'SetCallerID'  [app_substring.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => ((Deprecated) Save substring digits in a given variable)  == Registered application 'SubString'  [format_sln.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Raw Signed Linear Audio support (SLN))  == Registered file format sln, extension(s) sln|raw  [app_zapateller.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Block Telemarketers with Special Information Tone)  == Registered application 'Zapateller'  [app_queue.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (True Call Queueing)  == Registered application 'Queue'  == Manager registered action Queues  == Manager registered action QueueStatus  == Manager registered action QueueAdd  == Manager registered action QueueRemove  == Registered application 'AddQueueMember'  == Registered application 'RemoveQueueMember' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/queues.conf  [app_mp3.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Silly MP3 Application)  == Registered application 'MP3Player'  [app_lookupcidname.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Look up CallerID Name from local database)  == Registered application 'LookupCIDName'  [format_wav.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Microsoft WAV format (8000hz Signed Linear))  == Registered file format wav, extension(s) wav  [app_senddtmf.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Send DTMF digits Application)  == Registered application 'SendDTMF'  [format_vox.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Dialogic VOX (ADPCM) File Format)  == Registered file format vox, extension(s) vox  [app_waitforring.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Waits until first ring after time)  == Registered application 'WaitForRing'  [app_setcidnum.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Set CallerID Number)  == Registered application 'SetCIDNum'  [skipping chan_oss.so]  [app_talkdetect.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Playback with Talk Detection)  == Registered application 'BackgroundDetect'  [app_math.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Basic maths functions)  == Registered application 'Math'  [app_db.so]Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/modules.conf => (Database access functions for Asterisk extension logic)  == Registered application 'DBget'  == Registered application 'DBput'  == Registered application 'DBdel'  == Registered application 'DBdeltree' Nov 21 06:41:32 DEBUG[13172]: config.c:511 __ast_load: Parsing /etc/asterisk/enum.conf Asterisk Ready. ]1;Asterisk]2;Asterisk Console on 'minitokyo' (pid 13172)*CLI> h.323 trace 4 H.323 trace set to level 4 *CLI> h.3123223 edebug H323 debug enabled *CLI> Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:778 update_max_nontrunk: New max nontrunk callno is 2 Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:873 find_callno: Creating new call structure 1 Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 0, (6, 13) Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5386 socket_read: IAX subclass 13 received Urgent handler Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 11 on 1/16011 to 163.49.133.214:4569 Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 1, (6, 13) Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5289 socket_read: Cancelling transmission of packet 0 Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5386 socket_read: IAX subclass 13 received Urgent handler Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 47 on 1/16011 to 163.49.133.214:4569 Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 2, (6, 4) Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5289 socket_read: Cancelling transmission of packet 1 Nov 21 06:41:51 DEBUG[13188]: chan_iax2.c:5298 socket_read: Really destroying 1, having been acked on final message Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:778 update_max_nontrunk: New max nontrunk callno is 3 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:873 find_callno: Creating new call structure 2 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 0, (6, 1) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5386 socket_read: IAX subclass 1 received Urgent handler Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 19 on 2/16012 to 163.49.133.214:4569 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 1, (2, 2) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5345 socket_read: Ooh, voice format changed to 2 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 47 on 2/16012 to 163.49.133.214:4569 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 0, (6, 1) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5234 socket_read: Packet arrived out of order (expecting 2, got 0) (frametype = 6, subclass = 1) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5241 socket_read: Acking anyway Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 1 on 2/16012 to 163.49.133.214:4569 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 2, (6, 9) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5289 socket_read: Cancelling transmission of packet 0 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5386 socket_read: IAX subclass 9 received Urgent handler -- Accepting AUTHENTICATED call from 163.49.133.214, requested format = 2, actual format = 2 Urgent handler Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 80 on 2/16012 to 163.49.133.214:4569 Nov 21 06:41:59 DEBUG[13201]: app_queue.c:327 changethread: Device 'IAX2/4307@4307/2' changed to state '2' Nov 21 06:41:59 DEBUG[13201]: app_queue.c:353 changethread: Device 'IAX2/4307@4307/2' changed to state '2' Nov 21 06:41:59 DEBUG[13202]: pbx.c:1278 pbx_extension_helper: Launching 'Dial'  -- Executing Dial("IAX2/4307@4307/2", "H323/7814307@192.168.222.1") in new stack Urgent handler Nov 21 06:41:59 DEBUG[13202]: chan_h323.c:963 oh323_request: type=H323, format=4, data=7814307@192.168.222.1. Nov 21 06:41:59 DEBUG[13202]: chan_h323.c:996 oh323_request: Extension: 7814307 Host: 192.168.222.1 0:27.015 ThreadID=0x00058016 h323caps.cxx(1924) H323 Added capability: G.711-uLaw-64k <1> 0:27.017 ThreadID=0x00058016 h323caps.cxx(1986) H323 FinNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:2921 calc_rxstamp: calc_rxstamp: call=2: rxcore set to 1101040919.426172 - 64ms Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:2931 calc_rxstamp: calc_rxstamp: call=2: works out as 1101040919.362172 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=64 orig=64 last=0 VOICE: min=0 max=0 jb=6 +2 lateness=0 jbdelay=0 jitter=0 historic=0 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=64 dCapability: 1 0:27.020 ThreadID=0x00058016 h323caps.cxx(1990) H323 Found capability: G.711-uLaw-64k <1> 0:27.022 ThreadID=0x00058016 h323caps.cxx(1924) H323 Added capability: G.711-uLaw-64k <1> 0:27.025 ThreadID=0x00058016 h323caps.cxx(1986) H323 FindCapability: 1 0:27.027 ThreadID=0x00058016 h323caps.cxx(1990) H323 Found capability: G.711-uLaw-64k <1> 0:27.029 ThreadID=0x00058016 h323caps.cxx(2002) H323 FindCapability: "G.711-uLaw-64k" 0:27.032 ThreadID=0x00058016 h323caps.cxx(2011) H323 Found capability: G.711-uLaw-64k <1> 0:27.034 ThreadID=0x00058016 h323caps.cxx(1934) H323 RemoviNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=94 orig=94 last=64 VOICE: min=-14 max=0 jb=8 +2 lateness=-14 jbdelay=0 jitter=14 historic=14 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=94 ng capability: G.711-uLaw-64k <1> 0:27.037 ThreadID=0x00058016 h323caps.cxx(2002) H323 FindCapability: "G.711-uLaw-64k" 0:27.039 ThreadID=0x00058016 h323caps.cxx(1914) H323 Added capability: G.711-uLaw-64k <1> 0:27.042 ThreadID=0x00058016 h323caps.cxx(1924) H323 Added capability: G.711-uLaw-64k <1> 0:27.044 ThreadID=0x00058016 h323caps.cxx(1986) H323 FindCapability: 1 0:27.046 ThreadID=0x00058016 h323caps.cxx(1990) H323 Found capability: G.711-uLaw-64k <1> Allowed Codecs: Table: G.711-uLaw-64k <1> Set: 0: 0: G.711-uLaw-64k <1> Urgent handler Nov 21 06:41:59 DEBUG[13202]: chan_h323.c:441 oh323_call: Dest is 7814307@192.168.222.1 Nov 21 06:41:59 DEBUG[13202]: chan_h323.c:467 oh323_call: Placing outgoing call to 7814307@192.168.222.1 -- Making call to 7814307@192.168.222.1 using gatekeeper. 0:27.049 ThreadID=0x00058016 h323ep.cxx(1366) H323 Making call to: 7814307@192.168.222.1 0:27.052 ThreadID=0x00058016 h323caps.cxx(1924) H323 Added capability: G.711-uLaw-64k <1> 0:27.055 ThreadID=0x00058016 h323caps.cxx(1986) H323 FindCapability: 1 0:27.057 ThreadINov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 3, (6, 4) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5289 socket_read: Cancelling transmission of packet 1 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:5386 socket_read: IAX subclass 4 received D=0x00058Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=110 orig=110 last=94 VOICE: min=-14 max=0 jb=10 +0 lateness=-7 jbdelay=0 jitter=14 historic=14 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=110 016 h323caps.cxx(1990) H323 Found capability: G.711-uLaw-64k <1> 0:27.060 ThreadID=0x00058016 rfc2833.cxx(81) RFC2833 Handler created == New H.323 Connection created. 0:27.062 ThreadID=0x00058016 h323ep.cxx(1436) H323 Created new connection: ip$localhost/26725 -- conference-b is calling host 7814307@192.168.222.1 --Call token is ip$localhost/26725 -- Call reference is 26725  -- Called 7814307@192.168.222.1 Urgent handler Nov 21 06:41:59 DEBUG[13202]: channel.c:1747 ast_set_read_format: Set channel H323/192.168.222.1 to read format GSM Nov 21 06:41:59 DEBUG[13202]: channel.c:1714 ast_set_write_format: Set channel IAX2/4307@4307/2 to write format GSM Nov 21 06:41:59 DEBUG[13202]: channel.c:1714 ast_set_write_format: Set channel H323/192.168.222.1 to write format ULAW Nov 21 06:41:59 DEBUG[13202]: channel.c:1747 ast_set_read_format: Set channel IAX2/4307@4307/2 to read format ULAW 0:27.066 H225 Caller:81982e0 h323ep.cxx(740) H225 Started call thread 0:27.071 H225 Caller:81982e0 h323trans.cxx(519) Trans Making request: admissionRequest 0:27.074 H225 Caller:81982e0 h323pdu.cxx(513) Trans Sending PDU: admissionRequest { requestSeqNum = 25102 callType = pointToPoint <> endpointIdentifier = 9 characteNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=125 orig=125 last=110 VOICE: min=-14 max=0 jb=10 +0 lateness=-1 jbdelay=0 jitter=14 historic=13 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=125 rs { 0037 0038 0030 0035 005f 0065 006e 0064 7805_end 0070 p } destinationInfo = 1 entries { [0]=dialedDigits "7814307" } destCallSignalAddress = ipAddress { ip = 4 octets { c0 a8 de 01 .... } port = 1720 } srcInfo = 2 entries { [0]=h323_ID 12 characters { 0063 006f 006e 0066 0065 0072 0065 006e conferen 0063 0065 002d 0062 ce-b } [1]=dialedDigits "4489" } bandWidth = 100000 callReferenceValue = 26725 conferenceID = 16 octets { f2 ee 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=156 orig=156 last=125 VOICE: min=-14 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=14 historic=14 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=156 activeMC = FALSE answerCall = FALSE canMapAlias = TRUE callIdentifier = { guid = 16 octets { 8a e3 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } } gatekeeperIdentifier = 9 characters { 0047 006e 0075 0048 0033 0032 0033 0047 GnuH323G 004b K } willSupplyUUIEs = TRUE canMapSrcAlias = FALSE } 0:27.109 H225 Caller:81982e0 h323trans.cxx(650) Trans Waiting on response to seqnum=25102 for 3.0 seconds 0:27.113 Transactor:8131bd8 h323pdu.cxx(513) H225RAS Receiving PDU: admissionConfirm { requestSeqNum = 25102 bandWidth = 100000 callModel = direct <> destCallSignalAddress = ipAddress { ip = 4 octets { c0 a8 de 01 .... } port = 1720 } irrFrequency = 120 willRespondToIRR = FALSE uuiesRequested = { setup = FALSE callProceeding = FALSE connect = FALSE alerting = FALSE information = FALSE releaseComplete = FALSE facility = FALSE progress = FALSE empty = FALSE status = FALSE statusInquiry = FALSE setupAcknowledge = FALSE notify = FALSE } } 0:27.114 Transactor:8131bd8 h323trans.cxx(592) Trans Using credentials from request: H235AnnexD_Procedure1,MD5,CAT 0:27.116 H225 Caller:81982e0 h323.cxx(4550) H323 Bandwidth used: 0 0:27.118 H225 Caller:81982e0 transportNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=172 orig=172 last=156 VOICE: min=-14 max=0 jb=10 +0 lateness=-7 jbdelay=0 jitter=14 historic=13 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=172 s.cxx(1596) H323TCP Connecting to 192.168.222.1:1720 (local port=0) 0:27.124 GkMonitor:812a5b8 transports.cxx(986) TCP Appending H.225 transport ip$163.49.131.154:1720 using associated transport Transport[remote=ip$163.49.131.112:1719 if=ip$163.49.131.154:33827] 0:27.130 GkMonitor:812a5b8 h323.cxx(4550) H323 Bandwidth used: 0 0:27.132 GkMonitor:812a5b8 gkclient.cxx(1765) RAS Sending unsolicited IRR and without acknowledgement 0:27.135 GkMonitor:812a5b8 h323pdu.cxx(513)Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=188 orig=188 last=172 VOICE: min=-14 max=0 jb=10 +0 lateness=-7 jbdelay=0 jitter=14 historic=14 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=188 Trans Sending PDU: infoRequestResponse { requestSeqNum = 25103 endpointType = { vendor = { vendor = { t35CountryCode = 9 t35Extension = 0 manufacturerCode = 61 } productId = 56 octets { 54 68 65 20 4e 75 46 6f 6e 65 20 4e 65 74 77 6f The NuFone Netwo 72 6b 27 73 20 48 2e 33 32 33 20 43 68 61 6e 6e rk's H.323 Chann ... } versionId = 26 octets { 31 2e 30 2e 30 20 28 4f 70 65 6e 48 33 32 33 20 1.0.0 (OpenH323 76 31 2e 31 34 2e 34 29 00 00 v1.14.4).. } } terminal = { } mc = FALSE undefinedNode = FALSE } endpointIdentifier = 9 chNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=203 orig=203 last=188 VOICE: min=-14 max=0 jb=10 +0 lateness=-3 jbdelay=0 jitter=14 historic=13 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=203 aracters { 0037 0038 0030 0035 005f 0065 006e 0064 7805_end 0070 p } rasAddress = ipAddress { ip = 4 octets { a3 31 83 9a .1.. } port = 33827 } callSignalAddress = 1 entries { [0]=ipAddress { ip = 4 octets { a3 31 83 9a .1.. } port = 1720 } } endpointAlias = 2 entries { [0]=h323_ID 12 characters { 0063 006f 006e 0066 0065 0072 0065 006e conferen 0063 0065 002d 0062 ce-b } [1]=dialedDNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=235 orig=235 last=203 VOICE: min=-18 max=0 jb=10 +0 lateness=-18 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=235 igits "4489" } perCallInfo = 1 entries { [0]={ callReferenceValue = 26725 conferenceID = 16 octets { f2 ee 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } originator = TRUE h245 = { } callSignaling = { } callType = pointToPoint <> bandWidth = 0 callModel = direct <> callIdentifier = { guid = 16 octets { 8a e3 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } } substituteConfIDs = 0 entries { } usageInformation = { nonStandardUsageFields = 0 entries { } } } } needResponse = FALSE unsolicited = TRUE } 0:27.192 H225 Caller:81982e0 transports.cxx(1497) H323TCP Started connection: host=192.168.222.1:1720, if=163.49.131.154:46150, handle=41 0:27.196 H225 Caller:81982e0 h323.cxx(2899) H225 Sending Setup PDU 0:27.198 H225 Caller:81982e0 h323.cxx(2914) H225 Check for Fast start by local endpoint 0:27.200 H225 Caller:81982e0 h323.cxx(4094) H245 Default OnSelectLogicalChannels, FastStartInitiate Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=250 orig=250 last=235 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=250 Nov 21 06:41:59 DEBUG[13203]: chan_h323.c:1088 external_rtp_create: Sending RTP 'US' 0.0.0.0:18566 Nov 21 06:41:59 DEBUG[13203]: chan_h323.c:1088 external_rtp_create: Sending RTP 'US' 0.0.0.0:18566 0:27.204 H225 Caller:81982e0 h323.cxx(2920) H225 Fast start begun by local endpoint 0:27.207 H225 Caller:81982e0 channels.cxx(912) H323RTP OnSendingPDU 0:27.210 H225 Caller:81982e0 h323.cxx(1940) H225 Build fastStart: { forwardLogicalChannelNumber = 1 forwardLogicalChannelParameters = { dataType = nullData <> multiplexParameters = none <> } reverseLogicalChannelParameters = { dataType = audioData g711Ulaw64k 30 multiplexParameters = h2250LogicalChannelParameters { sessionID = 1 mediaChannel = unicastAddress iPAddress { network = 4 octets { 00 00 00 00 .... } tsapIdentifier = 18566 } mediaGuaranteedDelivery = FALSE mediaControlChannel = unicastAddress iPAddress { network = 4 octets { 00 00 00 00 .... } tsapIdentifier = 18567 } silenceSuppression = FALSE } } } 0:27.233 H225 Caller:81982e0 h323.cxx(1945) H225 Built fastStart for G.711-uLaw-64k <1> 0:27.237 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=266 orig=266 last=250 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=266 H225 Caller:81982e0 channels.cxx(912) H323RTP OnSendingPDU Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=297 orig=297 last=266 VOICE: min=-18 max=0 jb=10 +0 lateness=-12 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=297 0:27.241 H225 Caller:81982e0 h323.cxx(1940) H225 Build fastStart: { forwardLogicalChannelNumber = 101 forwardLogicalChannelParameters = { dataType = audioData g711Ulaw64k 30 multiplexParameters = h2250LogicalChannelParameters { sessionID = 1 mediaGuaranteedDelivery = FALSE mediaControlChannel = unicastAddress iPAddress { network = 4 octets { 00 00 00 00 .... } tsapIdentifier = 18567 } silenceSuppression = FALSE } } } 0:27.255 H225 Caller:81982e0 h323.cxx(1945) H225 Built fastStart for G.711-uLaw-64k <1> Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=313 orig=313 last=297 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=313 -- Sending SETUP message 0:27.258 H225 Caller:81982e0 h323.cxx(3280) H245 Started control channel 0:27.261 H225 Caller:81982e0 h323neg.cxx(549) H245 Sending TerminalCapabilitySet: outSeq=1 0:27.264 H225 Caller:81982e0 h323caps.cxx(2002) H323 FindCapability: "UserInput/RFC2833" 0:27.267 H225 Caller:81982e0 h323pdu.cxx(513) H245 Sending PDU: request terminalCapabilitySet { sequenceNumber = 1 protocolIdentifier = 0.0.8.245.0.7 multiplexCapability = h2250Capability { maximumAudioDelayJitter = 250 receiveMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=328 orig=328 last=313 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=328 ideo = FALSE distributedVideo = FALSE } } } transmitMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } receiveAndTransmitMultipointCapability = { multicastCapability = FALSE multiUniCastConference = FALSE mediaDistributionCapability = 1 entries { [0]={ centralizedControl = FALSE distributedControl = FALSE centralizedAudio = FALSE distributedAudio = FALSE centralizedVideo = FALSE distributedVideo = FALSE } } } mcCapability = { centralizedConferenceMC = FALSE decentralizedConferenceMC = FALSE } rtcpVideoControlCapability = FALSE mediaPacketizationCapability = { h261aVideoPacketization = FALSE } logicalChannelSwitchingCapability = FALSE t120DynamicPortCapability = TRUE } capabilityTable = 1 entries { [0]={ capabilityTableEntryNumber = 1 capability = receiveAudioCapability g711Ulaw64k 240 } } capabilityDescriptors = 1 entries { [0]={ capabilityDescriptorNumber = 1 simultaneousCapabilities = 1 entries { [0]=1 entries { [0]=1 } } } } } 0:27.321 H225 Caller:81982e0 h323neg.cxx(317) H245 Sending MasterSlaveDetermination Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=344 orig=344 last=328 VOICE: min=-18 max=0 jb=10 +0 lateness=-1 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=344 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=375 orig=375 last=344 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=375 0:27.324 H225 Caller:81982e0 h323pdu.cxx(513) H245 Sending PDU: request masterSlaveDetermination { terminalType = 50 statusDeterminationNumber = 9055494 } 0:27.329 H225 Caller:81982e0 h323pdu.cxx(513) H225 Sending PDU: { q931pdu = { protocolDiscriminator = 8 callReference = 26725 from = originator messageType = Setup IE: Bearer-Capability = { 80 90 a5 ... } IE: Display = { 63 6f 6e 66 65 72 65 6e 63 65 2d 62 00 conference-b. } IE: Calling-Party-Number = { 81 34 34 38 39 .4489 } IE: Called-Party-Number = { 81 37 38 31 34 33 30 37 .7814307 } IE: User-User = { 20 b8 06 00 08 91 4a 00 04 02 40 0b 00 63 00 6f .....J...@..c.o 00 6e 00 66 00 65 00 72 00 65 00 6e 00 63 00 65 .n.f.e.r.e.n.c.e ... } Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=391 orig=391 last=375 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=391 } h225pdu = { h323_uu_pdu = { h323_message_body = setup { protocolIdentifier = 0.0.8.2250.0.4 sourceAddress = 2 entries { [0]=h323_ID 12 characters { 0063 006f 006e 0066 0065 0072 0065 006e conferen 0063 0065 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=406 orig=406 last=391 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=406 002d 0062 ce-b } [1]=dialedDigits "4489" } sourceInfo = { vendor = { vendor = { t35CountryCode = 9 t35Extension = 0 manufacturerCode = 61 } productId = 56 octets { 54 68 65 20 4e 75 46 6f 6e 65 20 4e 65 74 77 6f The NuFone Netwo 72 6b 27 73 20 48 2e 33 32 33 20 43 68 61 6e 6e rk's H.323 Chann ... } versionId = 26 octets { 31 2e 30 2e 30 20 28 4f 70 65 6e 48 33 32 33 20 1.0.0 (OpenH323 76 31 2e 31 34 2e 34 29 00 00 v1.14.4).. } } terminal = { } mc = FALSE undefinedNode = FALSE } destinationAddress = 1 entries { [0]=dialedDigits "7814307" } desNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=438 orig=438 last=406 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=438 tCallSignalAddress = ipAddress { ip = 4 octets { c0 a8 de 01 .... } port = 1720 } activeMC = FALSE conferenceID = 16 octets { f2 ee 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } conferenceGoal = create <> callType = pointToPoint <> sourceCallSignalAddress = ipAddress { ip = 4 octets { a3 31 83 9a .1.. } port = 46150 } callIdentifier = { guid = 16 octets { 8a e3 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } } fastStart = 2 entries { [0]= 30 octets { 40 00 00 06 04 01 00 4c 60 1d 80 12 1d 00 01 00 @......L`....... 00 00 00 00 48 86 00 00 00 00 00 48 87 00 ....H......H.. } [1]= 19 octets { 00 00 64 0c 60 1d 80 0b 0d 00 01 00 00 00 00 00 ..d.`........... 48 87 00 H.. } } mediaWaitForConnect = FALSE canOverlapSend = FALSE multipleCalls = FALSE maintainConnection = FALSE parallelH245Control = 2 entries { [0]= 45 octets { 02 70 01 06 00 08 81 75 00 07 80 13 80 00 fa 00 .p.....u........ 01 00 00 01 00 00 01 00 00 0c c0 01 00 01 80Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=453 orig=453 last=438 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=453 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=469 orig=469 last=453 VOICE: min=-18 max=0 jb=10 +0 lateness=-3 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=469 00 ................ ... } [1]= 7 octets { 01 00 32 80 8a 2d 06 ..2..-. } } } h245Tunneling = TRUE } } } 0:27.428 H225 Caller:81982e0 h323.cxx(1675) H225 Reading PDUs: callRef=26725 0:27.431 H225 Caller:81982e0 h323pdu.cxx(1205) H225 Read error (0): 0:27.433 H225 Caller:81982e0 h323ep.cxx(1724) H323 Clearing connection ip$localhost/26725 reason=EndedByTransportFail 0:27.436 H225 CallNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=485 orig=485 last=469 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=485 er:81982e0 h323.cxx(1507) H323 Call end reason for ip$localhost/26725 set to EndedByTransportFail 0:27.439 H225 Caller:81982e0 h323.cxx(1525) H225 Sending release complete PDU: callRef=26725 -- Sending RELEASE COMPLETE 0:27.443 H225 Caller:81982e0 h323pdu.cxx(513) H245 Sending PDU: command endSessionCommand disconnect <> 0:27.447 H225 Caller:81982e0 h323pdu.cxx(513) H225 Sending PDU: { q931pdu = { protocolDiscriminator = 8 callReference = 26725 from = originator messageType = ReleaseComplete IE: User-User = { 25 c0 06 00 08 91 4a 00 04 58 08 11 00 8a e3 8d %.....J..X...... 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 04 c0 01 gNov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=516 orig=516 last=485 VOICE: min=-18 max=0 jb=10 +0 lateness=-15 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=516 (:........H.... ... } } h225pdu = { h323_uu_pdu = { h323_message_body = releaseComplete { protocolIdentifier = 0.0.8.2250.0.4 reason = undefinedReason <> callIdentifier = { guid = 16 octets { 8a e3 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } } } h245Tunneling = TRUE h245Control = 1 entries { [0]= 2 octets { 4a 40 J@ } } } } } 0:27.471 H225 Caller:81982e0 h323pdu.cxx(1259) H225 Write PDU failed (32): Broken pipe 0:27.474 H225 Caller:81982e0 h323ep.cxx(1724) H323 Clearing connection ip$localhost/26725 reason=EndedByTransportFail 0:27.477 H323 Cleaner h323ep.cxx(1781) H323 Cleaning up connections Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=531 orig=531 last=516 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=531 0:27.479 H323 Cleaner h323.cxx(1562) H323 Connection ip$localhost/26725 closing: connectionState=AwaitingSignalConnect 0:27.483 H323 Cleaner h323neg.cxx(334) H245 Stopping MasterSlaveDetermination: state=Outgoing 0:27.485 H323 Cleaner h323neg.cxx(561) H245 Stopping TerminalCapabilitySet: state=InProgress ExternalRTPChannel Destroyed 0:27.488 H323 Cleaner h323.cxx(4563) H323 Bandwidth request: -0.0kb/s, available: 10000.0kb/s ExternalRTPChannel Destroyed 0:27.491 H323 Cleaner h323.cxx(4563) H323 Bandwidth request: -0.0kb/s, available: 10000.0kb/s 0:27.494 H323 Cleaner h323.cxx(1605) H323 Awaiting end session from remote for 9.946 seconds Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=547 orig=547 last=531 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=547 0:27.496 H225 Caller:81982e0 transports.cxx(1102) H323 H323Transport::Close 0:27.499 H323 Cleaner transports.cxx(1102) H323 H323Transport::Close 0:27.501 H323 Cleaner transports.cxx(1184) H323 H323Transport::CleanUpOnTermination for H225 Caller:81982e0 0:27.504 H225 Caller:81982e0 h323.cxx(1718) H225 Signal channel closed. 0:27.515 H323 Cleaner h323trans.cxx(519) Trans Making request: disengageRequest 0:27.518 H323 Cleaner h323pdu.cxx(513) Trans Sending PDU: disengageRequest { requestSeqNum = 25104 endpointIdentifier = 9 characters { 0037 0038 0030 0035 005f 0065 006e 0064 7805_end 0070 p } conferenceID = 16 octets { f2 ee 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } callReferenceValue = 26725 disengageReason = normalDrop <> callIdentifier = { guid = 16 octets { 8a e3 8d 67 28 3a d9 11 96 09 00 0b cd 00 48 e3 ...g(:........H. } } gatekeeperIdentifier = 9 characters { 0047 006e 0075 0048 0033 0032 0033 0047 GnuH323G 004b K } answeredCall = FALSE usageInformation = { nonStandardUsageFields = 0 entries { } endTime = 1101040919 } terminationCause = releaseCompleteReason undefinedReason <> } 0:27.541 H323 Cleaner h323trans.cxx(650) Trans Waiting on response to seqnum=25104 for 3.0 seconds 0:27.544 Transactor:8131bd8 h323pdu.cxx(513) H225RAS Receiving PDU: disengageConfirm { requestSeqNum = 25104 } 0:27.545 Transactor:8131bd8 h323trans.cxx(592) Trans Using credentials from request: H235AnnexD_Procedure1,MD5,CAT 0:27.546 H323 Cleaner h323.cxx(1626) H323 Connection ip$localhost/26725 terminated. Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=563 orig=563 last=547 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=563 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=594 orig=594 last=563 VOICE: min=-18 max=0 jb=10 +0 lateness=0 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=594 -- Call with 7814307 ended abnormally == H.323 Connection deleted. 0:27.550 H323 Cleaner h323.cxx(1457) H323 Connection ip$localhost/26725 deleted. 0:27.552 H323 Cleaner h323ep.cxx(1781) H323 Cleaning up connections Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=610 orig=610 last=594 VOICE: min=-18 max=0 jb=10 +0 lateness=-11 jbdelay=0 jitter=18 historic=17 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=610 Nov 21 06:41:59 DEBUG[13202]: channel.c:745 ast_hangup: Hanging up channel 'H323/192.168.222.1' Nov 21 06:41:59 DEBUG[13202]: chan_h323.c:494 oh323_hangup: oh323_hangup(H323/192.168.222.1)  == No one is available to answer at this time Nov 21 06:41:59 DEBUG[13202]: app_dial.c:1090 dial_exec: Exiting with DIALSTATUS=NOANSWER. Nov 21 06:41:59 DEBUG[13202]: pbx.c:1278 pbx_extension_helper: Launching 'Congestion'  -- Executing Congestion("IAX2/4307@4307/2", "") in new stack Nov 21 06:41:59 DEBUG[13202]: chan_iax2.c:2634 iax2_indicate: Indicating condition 8 Urgent handler Urgent handler Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 83 on 2/16012 to 163.49.133.214:4569 Nov 21 06:41:59 DEBUG[13205]: app_queue.c:327 changethread: Device 'H323/192.168.222.1' changed to state '0' Nov 21 06:41:59 DEBUG[13205]: app_queue.c:353 changethread: Device 'H323/192.168.222.1' changed to state '0' Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=625 orig=625 last=610 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=18 Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:41:59 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=625 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=656 orig=656 last=625 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=656 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=672 orig=672 last=656 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=672 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=688 orig=688 last=672 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=688 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=703 orig=703 last=688 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=703 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=735 orig=735 last=703 VOICE: min=-18 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=735 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=750 orig=750 last=735 VOICE: min=-18 max=0 jb=10 +0 lateness=-9 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=750 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=766 orig=766 last=750 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=766 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=797 orig=797 last=766 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=797 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=813 orig=813 last=797 VOICE: min=-18 max=0 jb=10 +0 lateness=-15 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=813 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=828 orig=828 last=813 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=828 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=844 orig=844 last=828 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=844 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=875 orig=875 last=844 VOICE: min=-18 max=0 jb=10 +0 lateness=-12 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=875 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=891 orig=891 last=875 VOICE: min=-18 max=0 jb=10 +0 lateness=-11 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=891 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=906 orig=906 last=891 VOICE: min=-18 max=0 jb=10 +0 lateness=-7 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=906 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=938 orig=938 last=906 VOICE: min=-18 max=0 jb=10 +0 lateness=-17 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=938 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=953 orig=953 last=938 VOICE: min=-18 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=953 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=969 orig=969 last=953 VOICE: min=-18 max=0 jb=10 +0 lateness=0 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=969 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=985 orig=985 last=969 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=985 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1016 orig=1016 last=985 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1016 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1031 orig=1031 last=1016 VOICE: min=-18 max=0 jb=10 +0 lateness=-10 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1031 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1047 orig=1047 last=1031 VOICE: min=-18 max=0 jb=10 +0 lateness=-9 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1047 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1078 orig=1078 last=1047 VOICE: min=-18 max=0 jb=10 +0 lateness=-16 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1078 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1094 orig=1094 last=1078 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1094 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1110 orig=1110 last=1094 VOICE: min=-18 max=0 jb=10 +0 lateness=-7 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1110 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1125 orig=1125 last=1110 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1125 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1141 orig=1141 last=1125 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1141 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1172 orig=1172 last=1141 VOICE: min=-18 max=0 jb=10 +0 lateness=-11 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1172 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1188 orig=1188 last=1172 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1188 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1219 orig=1219 last=1188 VOICE: min=-18 max=0 jb=10 +0 lateness=-18 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1219 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1235 orig=1235 last=1219 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1235 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1250 orig=1250 last=1235 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1250 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1266 orig=1266 last=1250 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1266 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1281 orig=1281 last=1266 VOICE: min=-18 max=0 jb=10 +0 lateness=-3 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1281 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1313 orig=1313 last=1281 VOICE: min=-18 max=0 jb=10 +0 lateness=-11 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1313 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1328 orig=1328 last=1313 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1328 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1360 orig=1360 last=1328 VOICE: min=-18 max=0 jb=10 +0 lateness=-17 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1360 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1375 orig=1375 last=1360 VOICE: min=-18 max=0 jb=10 +0 lateness=-15 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1375 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1391 orig=1391 last=1375 VOICE: min=-18 max=0 jb=10 +0 lateness=-12 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1391 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1406 orig=1406 last=1391 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1406 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1422 orig=1422 last=1406 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1422 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1453 orig=1453 last=1422 VOICE: min=-18 max=0 jb=10 +0 lateness=-9 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1453 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1469 orig=1469 last=1453 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1469 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1485 orig=1485 last=1469 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1485 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1516 orig=1516 last=1485 VOICE: min=-18 max=0 jb=10 +0 lateness=-15 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1516 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1531 orig=1531 last=1516 VOICE: min=-18 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1531 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1547 orig=1547 last=1531 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1547 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1563 orig=1563 last=1547 VOICE: min=-18 max=0 jb=10 +0 lateness=-3 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1563 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1594 orig=1594 last=1563 VOICE: min=-18 max=0 jb=10 +0 lateness=-11 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1594 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1610 orig=1610 last=1594 VOICE: min=-18 max=0 jb=10 +0 lateness=-10 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1610 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1625 orig=1625 last=1610 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:00 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1625 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1656 orig=1656 last=1625 VOICE: min=-18 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1656 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1672 orig=1672 last=1656 VOICE: min=-18 max=0 jb=10 +0 lateness=-12 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1672 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1688 orig=1688 last=1672 VOICE: min=-18 max=0 jb=10 +0 lateness=-4 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1688 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1703 orig=1703 last=1688 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1703 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1735 orig=1735 last=1703 VOICE: min=-18 max=0 jb=10 +0 lateness=-18 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1735 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1750 orig=1750 last=1735 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1750 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1766 orig=1766 last=1750 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1766 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1797 orig=1797 last=1766 VOICE: min=-18 max=0 jb=10 +0 lateness=-15 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1797 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1813 orig=1813 last=1797 VOICE: min=-18 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1813 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1828 orig=1828 last=1813 VOICE: min=-18 max=0 jb=10 +0 lateness=-5 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1828 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1844 orig=1844 last=1828 VOICE: min=-18 max=0 jb=10 +0 lateness=-2 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1844 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1875 orig=1875 last=1844 VOICE: min=-18 max=0 jb=10 +0 lateness=-16 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1875 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1891 orig=1891 last=1875 VOICE: min=-18 max=0 jb=10 +0 lateness=-8 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1891 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1906 orig=1906 last=1891 VOICE: min=-18 max=0 jb=10 +0 lateness=-6 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1906 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1938 orig=1938 last=1906 VOICE: min=-18 max=0 jb=10 +0 lateness=-14 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1938 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1953 orig=1953 last=1938 VOICE: min=-18 max=0 jb=10 +0 lateness=-12 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1953 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1969 orig=1969 last=1953 VOICE: min=-18 max=0 jb=10 +0 lateness=-9 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1969 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=1985 orig=1985 last=1969 VOICE: min=-18 max=0 jb=10 +0 lateness=-1 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=1985 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2016 orig=2016 last=1985 VOICE: min=-18 max=0 jb=10 +0 lateness=-15 jbdelay=0 jitter=18 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2016 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2031 orig=2031 last=2016 VOICE: min=-18 max=0 jb=10 +0 lateness=-13 jbdelay=0 jitter=18 historic=18 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2031 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2047 orig=2047 last=2031 VOICE: min=-18 max=-1 jb=10 +0 lateness=-5 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2047 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2063 orig=2063 last=2047 VOICE: min=-18 max=-1 jb=10 +0 lateness=-4 jbdelay=0 jitter=17 historic=16 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2063 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2094 orig=2094 last=2063 VOICE: min=-18 max=-1 jb=10 +0 lateness=-12 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2094 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2110 orig=2110 last=2094 VOICE: min=-18 max=-1 jb=10 +0 lateness=-8 jbdelay=0 jitter=17 historic=16 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2110 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2125 orig=2125 last=2110 VOICE: min=-18 max=-1 jb=10 +0 lateness=-1 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2125 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2156 orig=2156 last=2125 VOICE: min=-18 max=-1 jb=10 +0 lateness=-16 jbdelay=0 jitter=17 historic=16 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2156 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2172 orig=2172 last=2156 VOICE: min=-18 max=-1 jb=10 +0 lateness=-13 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2172 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2188 orig=2188 last=2172 VOICE: min=-18 max=-1 jb=10 +0 lateness=-7 jbdelay=0 jitter=17 historic=16 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2188 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2203 orig=2203 last=2188 VOICE: min=-18 max=-1 jb=10 +0 lateness=-3 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2203 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2235 orig=2235 last=2203 VOICE: min=-18 max=-1 jb=10 +0 lateness=-11 jbdelay=0 jitter=17 historic=16 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2235 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2250 orig=2250 last=2235 VOICE: min=-18 max=-1 jb=10 +0 lateness=-9 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2250 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2266 orig=2266 last=2250 VOICE: min=-18 max=-1 jb=10 +0 lateness=-8 jbdelay=0 jitter=17 historic=16 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2266 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1906 schedule_delivery: Jitter: call=2 ts=2297 orig=2297 last=2266 VOICE: min=-18 max=-1 jb=10 +0 lateness=-15 jbdelay=0 jitter=17 historic=17 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1919 schedule_delivery: schedule_delivery: Delivering immediately (Calculated delay is 0) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:6060 socket_read: For call=2, set last=2297 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:5199 socket_read: Received packet 3, (6, 5) Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:5289 socket_read: Cancelling transmission of packet 2 Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:5386 socket_read: IAX subclass 5 received Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:5527 socket_read: Immediately destroying 2, having received hangup Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:1272 send_packet: Sending 2298 on 2/16012 to 163.49.133.214:4569 Nov 21 06:42:01 DEBUG[13202]: pbx.c:1919 ast_pbx_run: Spawn extension (default,7814307,2) exited non-zero on 'IAX2/4307@4307/2' Nov 21 06:42:01 DEBUG[13202]: channel.c:745 ast_hangup: Hanging up channel 'IAX2/4307@4307/2' Nov 21 06:42:01 DEBUG[13202]: chan_iax2.c:2384 iax2_hangup: We're hanging up IAX2/4307@4307/2 now... Nov 21 06:42:01 DEBUG[13202]: chan_iax2.c:2393 iax2_hangup: Really destroying IAX2/4307@4307/2 now...  -- Hungup 'IAX2/4307@4307/2' Urgent handler Nov 21 06:42:01 DEBUG[13207]: app_queue.c:327 changethread: Device 'IAX2/4307@4307/2' changed to state '0' Nov 21 06:42:01 DEBUG[13207]: app_queue.c:353 changethread: Device 'IAX2/4307@4307/2' changed to state '0' Nov 21 06:42:01 DEBUG[13188]: chan_iax2.c:3779 raw_hangup: Raw Hangup 163.49.133.214:4569, src=2, dst=16012 *CLI> stop now  Beginning asterisk shutdown.... Urgent handler Executing last minute cleanups Urgent handler  == Destroying any remaining musiconhold processes Urgent handler Nov 21 06:42:10 DEBUG[13172]: res_musiconhold.c:643 ast_moh_destroy: killing 13184! Nov 21 06:42:10 DEBUG[13172]: res_musiconhold.c:649 ast_moh_destroy: mpg123 pid 13184 and child died after 184 bytes read Asterisk cleanly ending (0). Urgent handler minitokyo:~ # Script done on Sun Nov 21 06:42:12 2004