Parsing /etc/asterisk/asterisk.conf Parsing /etc/asterisk/extconfig.conf [Dec 4 14:20:32] == Parsing '/etc/asterisk/asterisk.conf': [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Parsing '/etc/asterisk/extconfig.conf': [Dec 4 14:20:32] Found [Dec 4 14:20:32] Asterisk 1.2.14, Copyright (C) 1999 - 2006 Digium, Inc. and others. [Dec 4 14:20:32] Created by Mark Spencer [Dec 4 14:20:32] Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. [Dec 4 14:20:32] This is free software, with components licensed under the GNU General Public [Dec 4 14:20:32] License version 2 and other licenses; you are welcome to redistribute it under [Dec 4 14:20:32] certain conditions. Type 'show license' for details. [Dec 4 14:20:32] ========================================================================= [Dec 4 14:20:32] == Parsing '/etc/asterisk/logger.conf': Parsing /etc/asterisk/logger.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] Asterisk Event Logger Started /var/log/asterisk/event_log [Dec 4 14:20:32] == Parsing '/etc/asterisk/dnsmgr.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/dnsmgr.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] Asterisk Dynamic Loader loading preload modules: [Dec 4 14:20:32] == Parsing '/etc/asterisk/modules.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/modules.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Manager registered action Ping [Dec 4 14:20:32] == Manager registered action Events [Dec 4 14:20:32] == Manager registered action Logoff [Dec 4 14:20:32] == Manager registered action Hangup [Dec 4 14:20:32] == Manager registered action Status [Dec 4 14:20:32] == Manager registered action Setvar [Dec 4 14:20:32] == Manager registered action Getvar [Dec 4 14:20:32] == Manager registered action Redirect [Dec 4 14:20:32] == Manager registered action Originate [Dec 4 14:20:32] == Manager registered action Command [Dec 4 14:20:32] == Manager registered action ExtensionState [Dec 4 14:20:32] == Manager registered action AbsoluteTimeout [Dec 4 14:20:32] == Manager registered action MailboxStatus [Dec 4 14:20:32] == Manager registered action MailboxCount [Dec 4 14:20:32] == Manager registered action ListCommands [Dec 4 14:20:32] == Parsing '/etc/asterisk/manager.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/manager.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] Asterisk Management interface listening on port 5038 [Dec 4 14:20:32] == Parsing '/etc/asterisk/cdr.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/cdr.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] NOTICE[12994]: cdr.c:1192 do_reload: CDR simple logging enabled. [Dec 4 14:20:32] == Parsing '/etc/asterisk/rtp.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/rtp.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] == RTP Allocating from port range 10000 -> 20000 [Dec 4 14:20:32] Asterisk PBX Core Initializing [Dec 4 14:20:32] Registering builtin applications: [Dec 4 14:20:32] [AbsoluteTimeout] [Dec 4 14:20:32] == Registered application 'AbsoluteTimeout' [Dec 4 14:20:32] [Answer] [Dec 4 14:20:32] == Registered application 'Answer' [Dec 4 14:20:32] [BackGround] [Dec 4 14:20:32] == Registered application 'BackGround' [Dec 4 14:20:32] [Busy] [Dec 4 14:20:32] == Registered application 'Busy' [Dec 4 14:20:32] [Congestion] [Dec 4 14:20:32] == Registered application 'Congestion' [Dec 4 14:20:32] [DigitTimeout] [Dec 4 14:20:32] == Registered application 'DigitTimeout' [Dec 4 14:20:32] [Goto] [Dec 4 14:20:32] == Registered application 'Goto' [Dec 4 14:20:32] [GotoIf] [Dec 4 14:20:32] == Registered application 'GotoIf' [Dec 4 14:20:32] [GotoIfTime] [Dec 4 14:20:32] == Registered application 'GotoIfTime' [Dec 4 14:20:32] [ExecIfTime] [Dec 4 14:20:32] == Registered application 'ExecIfTime' [Dec 4 14:20:32] [Hangup] [Dec 4 14:20:32] == Registered application 'Hangup' [Dec 4 14:20:32] [NoOp] [Dec 4 14:20:32] == Registered application 'NoOp' [Dec 4 14:20:32] [Progress] [Dec 4 14:20:32] == Registered application 'Progress' [Dec 4 14:20:32] [ResetCDR] [Dec 4 14:20:32] == Registered application 'ResetCDR' [Dec 4 14:20:32] [ResponseTimeout] [Dec 4 14:20:32] == Registered application 'ResponseTimeout' [Dec 4 14:20:32] [Ringing] [Dec 4 14:20:32] == Registered application 'Ringing' [Dec 4 14:20:32] [SayNumber] [Dec 4 14:20:32] == Registered application 'SayNumber' [Dec 4 14:20:32] [SayDigits] [Dec 4 14:20:32] == Registered application 'SayDigits' [Dec 4 14:20:32] [SayAlpha] [Dec 4 14:20:32] == Registered application 'SayAlpha' [Dec 4 14:20:32] [SayPhonetic] [Dec 4 14:20:32] == Registered application 'SayPhonetic' [Dec 4 14:20:32] [SetAccount] [Dec 4 14:20:32] == Registered application 'SetAccount' [Dec 4 14:20:32] [SetAMAFlags] [Dec 4 14:20:32] == Registered application 'SetAMAFlags' [Dec 4 14:20:32] [SetGlobalVar] [Dec 4 14:20:32] == Registered application 'SetGlobalVar' [Dec 4 14:20:32] [SetLanguage] [Dec 4 14:20:32] == Registered application 'SetLanguage' [Dec 4 14:20:32] [Set] [Dec 4 14:20:32] == Registered application 'Set' [Dec 4 14:20:32] [SetVar] [Dec 4 14:20:32] == Registered application 'SetVar' [Dec 4 14:20:32] [ImportVar] [Dec 4 14:20:32] == Registered application 'ImportVar' [Dec 4 14:20:32] [Wait] [Dec 4 14:20:32] == Registered application 'Wait' [Dec 4 14:20:32] [WaitExten] [Dec 4 14:20:32] == Registered application 'WaitExten' [Dec 4 14:20:32] == Manager registered action DBGet [Dec 4 14:20:32] == Manager registered action DBPut [Dec 4 14:20:32] == Parsing '/etc/asterisk/enum.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/enum.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] Asterisk Dynamic Loader Starting: [Dec 4 14:20:32] == Parsing '/etc/asterisk/modules.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/modules.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] [res_features.so][Dec 4 14:20:32] => (Call Features Resource) [Dec 4 14:20:32] == Parsing '/etc/asterisk/features.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/features.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Remapping feature One Touch Monitor (automon) to sequence '*1' [Dec 4 14:20:32] == Remapping feature Attended Transfer (atxfer) to sequence '*2' [Dec 4 14:20:32] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'parkedcalls' [Dec 4 14:20:32] -- Registered extension context 'parkedcalls' [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '700' priority 1 to parkedcalls [Dec 4 14:20:32] -- Added extension '700' priority 1 to parkedcalls [Dec 4 14:20:32] == Registered application 'ParkedCall' [Dec 4 14:20:32] == Registered application 'Park' [Dec 4 14:20:32] == Manager registered action ParkedCalls [Dec 4 14:20:32] [app_directed_pickup.so][Dec 4 14:20:32] => (Directed Call Pickup Application) [Dec 4 14:20:32] == Registered application 'Pickup' [Dec 4 14:20:32] [res_musiconhold.so][Dec 4 14:20:32] => (Music On Hold Resource) [Dec 4 14:20:32] == Registered application 'MusicOnHold' [Dec 4 14:20:32] == Registered application 'WaitMusicOnHold' [Dec 4 14:20:32] == Registered application 'SetMusicOnHold' [Dec 4 14:20:32] == Registered application 'StartMusicOnHold' [Dec 4 14:20:32] == Registered application 'StopMusicOnHold' [Dec 4 14:20:32] == Parsing '/etc/asterisk/musiconhold.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/musiconhold.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] WARNING[12994]: res_musiconhold.c:867 moh_register: Unable to open pseudo channel for timing... Sound may be choppy. [Dec 4 14:20:32] [res_indications.so][Dec 4 14:20:32] WARNING[13001]: res_musiconhold.c:422 spawn_mp3: Found no files in '/usr/share/asterisk/mohmp3' [Dec 4 14:20:32] WARNING[13001]: res_musiconhold.c:504 monmp3thread: Unable to spawn mp3player [Dec 4 14:20:32] => (Indications Configuration) [Dec 4 14:20:32] == Parsing '/etc/asterisk/indications.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/indications.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] -- Registered indication country 'at' [Dec 4 14:20:32] -- Registered indication country 'au' [Dec 4 14:20:32] -- Registered indication country 'br' [Dec 4 14:20:32] -- Registered indication country 'be' [Dec 4 14:20:32] -- Registered indication country 'ch' [Dec 4 14:20:32] -- Registered indication country 'cl' [Dec 4 14:20:32] -- Registered indication country 'cn' [Dec 4 14:20:32] -- Registered indication country 'cz' [Dec 4 14:20:32] -- Registered indication country 'de' [Dec 4 14:20:32] -- Registered indication country 'dk' [Dec 4 14:20:32] -- Registered indication country 'ee' [Dec 4 14:20:32] -- Registered indication country 'es' [Dec 4 14:20:32] -- Registered indication country 'fi' [Dec 4 14:20:32] -- Registered indication country 'fr' [Dec 4 14:20:32] -- Registered indication country 'gr' [Dec 4 14:20:32] -- Registered indication country 'hu' [Dec 4 14:20:32] -- Registered indication country 'it' [Dec 4 14:20:32] -- Registered indication country 'lt' [Dec 4 14:20:32] -- Registered indication country 'mx' [Dec 4 14:20:32] -- Registered indication country 'nl' [Dec 4 14:20:32] -- Registered indication country 'no' [Dec 4 14:20:32] -- Registered indication country 'nz' [Dec 4 14:20:32] -- Registered indication country 'pl' [Dec 4 14:20:32] -- Registered indication country 'pt' [Dec 4 14:20:32] -- Registered indication country 'ru' [Dec 4 14:20:32] -- Registered indication country 'se' [Dec 4 14:20:32] -- Registered indication country 'sg' [Dec 4 14:20:32] -- Registered indication country 'uk' [Dec 4 14:20:32] -- Registered indication country 'us' [Dec 4 14:20:32] -- Registered indication country 'us-o' [Dec 4 14:20:32] -- Registered indication country 'tw' [Dec 4 14:20:32] -- Registered indication country 've' [Dec 4 14:20:32] -- Registered indication country 'za' [Dec 4 14:20:32] -- Setting default indication country to 'us' [Dec 4 14:20:32] == Registered application 'PlayTones' [Dec 4 14:20:32] == Registered application 'StopPlayTones' [Dec 4 14:20:32] [res_monitor.so][Dec 4 14:20:32] => (Call Monitoring Resource) [Dec 4 14:20:32] == Registered application 'Monitor' [Dec 4 14:20:32] == Registered application 'StopMonitor' [Dec 4 14:20:32] == Registered application 'ChangeMonitor' [Dec 4 14:20:32] == Manager registered action Monitor [Dec 4 14:20:32] == Manager registered action StopMonitor [Dec 4 14:20:32] == Manager registered action ChangeMonitor [Dec 4 14:20:32] [res_adsi.so][Dec 4 14:20:32] => (ADSI Resource) [Dec 4 14:20:32] == Parsing '/etc/asterisk/adsi.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/adsi.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] [res_agi.so][Dec 4 14:20:32] => (Asterisk Gateway Interface (AGI)) [Dec 4 14:20:32] == Registered application 'DeadAGI' [Dec 4 14:20:32] == Registered application 'EAGI' [Dec 4 14:20:32] == Registered application 'AGI' [Dec 4 14:20:32] [skipping res_config_odbc.so] [Dec 4 14:20:32] [res_odbc.so][Dec 4 14:20:32] => (ODBC Resource) [Dec 4 14:20:32] == Parsing '/etc/asterisk/res_odbc.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/res_odbc.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] NOTICE[12994]: res_odbc.c:266 load_odbc_config: Adding ENV var: INFORMIXSERVER=my_special_database [Dec 4 14:20:32] NOTICE[12994]: res_odbc.c:266 load_odbc_config: Adding ENV var: INFORMIXDIR=/opt/informix [Dec 4 14:20:32] NOTICE[12994]: res_odbc.c:295 load_odbc_config: registered database handle 'asterisk' dsn->[asterisk] [Dec 4 14:20:32] NOTICE[12994]: res_odbc.c:555 odbc_obj_connect: Connecting asterisk [Dec 4 14:20:32] WARNING[12994]: res_odbc.c:566 odbc_obj_connect: res_odbc: Error SQLConnect=-1 errno=0 [unixODBC][Driver Manager]Data source name not found, and no default driver specified [Dec 4 14:20:32] NOTICE[12994]: res_odbc.c:600 load_module: res_odbc loaded. [Dec 4 14:20:32] [res_crypto.so][Dec 4 14:20:32] => (Cryptographic Digital Signatures) [Dec 4 14:20:32] -- Loaded PUBLIC key 'freeworlddialup' [Dec 4 14:20:32] DEBUG[12994]: res_crypto.c:257 try_load_key: Key 'freeworlddialup' loaded OK [Dec 4 14:20:32] -- Loaded PUBLIC key 'iaxtel' [Dec 4 14:20:32] DEBUG[12994]: res_crypto.c:257 try_load_key: Key 'iaxtel' loaded OK [Dec 4 14:20:32] [skipping res_config_mysql.so] [Dec 4 14:20:32] [pbx_config.so][Dec 4 14:20:32] => (Text Extension Configuration) [Dec 4 14:20:32] == Parsing '/etc/asterisk/extensions.conf': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/extensions.conf [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Parsing '/etc/asterisk/queue-extensions': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/queue-extensions [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Parsing '/etc/asterisk/text-handling-extensions': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/text-handling-extensions [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Parsing '/etc/asterisk/macros': [Dec 4 14:20:32] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/macros [Dec 4 14:20:32] Found [Dec 4 14:20:32] == Setting global variable 'CONSOLE' to 'Console/dsp' [Dec 4 14:20:32] == Setting global variable 'DYNAMIC_FEATURES' to 'automon' [Dec 4 14:20:32] == Setting global variable 'DYNAMIC_FEATURES' to 'atxfer' [Dec 4 14:20:32] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'west1' [Dec 4 14:20:32] -- Registered extension context 'west1' [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 1 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 2 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 3 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 4 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 5 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 6 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 7 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to west1 [Dec 4 14:20:32] -- Added extension 's' priority 8 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to west1 [Dec 4 14:20:32] -- Added extension 's-TIMEOUT' priority 1 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to west1 [Dec 4 14:20:32] -- Added extension 's-TIMEOUT' priority 2 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to west1 [Dec 4 14:20:32] -- Added extension 's-FULL' priority 1 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to west1 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 1 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to west1 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 2 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to west1 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 3 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to west1 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 4 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to west1 [Dec 4 14:20:32] -- Added extension 's-LEAVEUNAVAIL' priority 1 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to west1 [Dec 4 14:20:32] -- Added extension '_s-.' priority 1 to west1 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'west2' [Dec 4 14:20:32] -- Registered extension context 'west2' [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 1 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 2 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 3 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 4 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 5 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 6 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 7 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to west2 [Dec 4 14:20:32] -- Added extension 's' priority 8 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to west2 [Dec 4 14:20:32] -- Added extension 's-TIMEOUT' priority 1 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to west2 [Dec 4 14:20:32] -- Added extension 's-TIMEOUT' priority 2 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to west2 [Dec 4 14:20:32] -- Added extension 's-FULL' priority 1 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to west2 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 1 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to west2 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 2 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to west2 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 3 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to west2 [Dec 4 14:20:32] -- Added extension 's-JOINUNAVAIL' priority 4 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to west2 [Dec 4 14:20:32] -- Added extension 's-LEAVEUNAVAIL' priority 1 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to west2 [Dec 4 14:20:32] -- Added extension '_s-.' priority 1 to west2 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'west3' [Dec 4 14:20:32] -- Registered extension context 'west3' [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to west3 [Dec 4 14:20:32] -- Added extension 's' priority 1 to west3 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to west3 [Dec 4 14:20:32] -- Added extension 's' priority 2 to west3 [Dec 4 14:20:32] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to west3 [Dec 4 14:20:32] -- Added extension 's' priority 3 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to west3 [Dec 4 14:20:33] -- Added extension 's' priority 4 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to west3 [Dec 4 14:20:33] -- Added extension 's' priority 5 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to west3 [Dec 4 14:20:33] -- Added extension 's' priority 6 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to west3 [Dec 4 14:20:33] -- Added extension 's' priority 7 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to west3 [Dec 4 14:20:33] -- Added extension 's' priority 8 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to west3 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to west3 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to west3 [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to west3 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to west3 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to west3 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to west3 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 4 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to west3 [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to west3 [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to west3 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'west4' [Dec 4 14:20:33] -- Registered extension context 'west4' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 1 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 2 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 3 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 4 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 5 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 6 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 7 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to west4 [Dec 4 14:20:33] -- Added extension 's' priority 8 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to west4 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to west4 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to west4 [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to west4 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to west4 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to west4 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to west4 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 4 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to west4 [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to west4 [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to west4 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'west5' [Dec 4 14:20:33] -- Registered extension context 'west5' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 1 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 2 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 3 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 4 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 5 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 6 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 7 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to west5 [Dec 4 14:20:33] -- Added extension 's' priority 8 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to west5 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to west5 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to west5 [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to west5 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to west5 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to west5 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to west5 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 4 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to west5 [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to west5 [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to west5 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'west6' [Dec 4 14:20:33] -- Registered extension context 'west6' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 1 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 2 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 3 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 4 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 5 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 6 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 7 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to west6 [Dec 4 14:20:33] -- Added extension 's' priority 8 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to west6 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to west6 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to west6 [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to west6 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to west6 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to west6 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to west6 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 4 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to west6 [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to west6 [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to west6 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'ost1' [Dec 4 14:20:33] -- Registered extension context 'ost1' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 1 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 2 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 3 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 4 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 5 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 6 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 7 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to ost1 [Dec 4 14:20:33] -- Added extension 's' priority 8 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to ost1 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to ost1 [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to ost1 [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to ost1 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to ost1 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to ost1 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to ost1 [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 4 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to ost1 [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to ost1 [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to ost1 [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'edv' [Dec 4 14:20:33] -- Registered extension context 'edv' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to edv [Dec 4 14:20:33] -- Added extension 's' priority 1 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to edv [Dec 4 14:20:33] -- Added extension 's' priority 2 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to edv [Dec 4 14:20:33] -- Added extension 's' priority 3 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to edv [Dec 4 14:20:33] -- Added extension 's' priority 4 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to edv [Dec 4 14:20:33] -- Added extension 's' priority 5 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to edv [Dec 4 14:20:33] -- Added extension 's' priority 6 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to edv [Dec 4 14:20:33] -- Added extension 's' priority 7 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to edv [Dec 4 14:20:33] -- Added extension 's' priority 8 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to edv [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to edv [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to edv [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to edv [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to edv [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to edv [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 4 to edv [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 4 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to edv [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to edv [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to edv [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'zentrale' [Dec 4 14:20:33] -- Registered extension context 'zentrale' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 1 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 2 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 3 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 4 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 5 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 6 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 7 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 8 to zentrale [Dec 4 14:20:33] -- Added extension 's' priority 8 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-TIMEOUT' priority 1 to zentrale [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 1 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-TIMEOUT' priority 2 to zentrale [Dec 4 14:20:33] -- Added extension 's-TIMEOUT' priority 2 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-FULL' priority 1 to zentrale [Dec 4 14:20:33] -- Added extension 's-FULL' priority 1 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 1 to zentrale [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 1 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 2 to zentrale [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 2 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-JOINUNAVAIL' priority 3 to zentrale [Dec 4 14:20:33] -- Added extension 's-JOINUNAVAIL' priority 3 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-LEAVEUNAVAIL' priority 1 to zentrale [Dec 4 14:20:33] -- Added extension 's-LEAVEUNAVAIL' priority 1 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to zentrale [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to zentrale [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'aufnahme' [Dec 4 14:20:33] -- Registered extension context 'aufnahme' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 1 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 2 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 3 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 4 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 5 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 6 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 7 to aufnahme [Dec 4 14:20:33] -- Added extension 's' priority 7 to aufnahme [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'playback' [Dec 4 14:20:33] -- Registered extension context 'playback' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to playback [Dec 4 14:20:33] -- Added extension 's' priority 1 to playback [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to playback [Dec 4 14:20:33] -- Added extension 's' priority 2 to playback [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to playback [Dec 4 14:20:33] -- Added extension 's' priority 3 to playback [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to playback [Dec 4 14:20:33] -- Added extension 's' priority 4 to playback [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to playback [Dec 4 14:20:33] -- Added extension 's' priority 5 to playback [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to playback [Dec 4 14:20:33] -- Added extension 's' priority 6 to playback [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-stddial' [Dec 4 14:20:33] -- Registered extension context 'macro-stddial' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-RingDown' [Dec 4 14:20:33] -- Registered extension context 'macro-RingDown' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-agent' [Dec 4 14:20:33] -- Registered extension context 'macro-agent' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-office' [Dec 4 14:20:33] -- Registered extension context 'macro-office' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-double' [Dec 4 14:20:33] -- Registered extension context 'macro-double' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-Double-Fail' [Dec 4 14:20:33] -- Registered extension context 'macro-Double-Fail' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-double-check' [Dec 4 14:20:33] -- Registered extension context 'macro-double-check' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-doubleext' [Dec 4 14:20:33] -- Registered extension context 'macro-doubleext' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-triplecall' [Dec 4 14:20:33] -- Registered extension context 'macro-triplecall' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-specialtriple' [Dec 4 14:20:33] -- Registered extension context 'macro-specialtriple' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-test1' [Dec 4 14:20:33] -- Registered extension context 'macro-test1' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-test2' [Dec 4 14:20:33] -- Registered extension context 'macro-test2' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'macro-stdexten' [Dec 4 14:20:33] -- Registered extension context 'macro-stdexten' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to macro-stdexten [Dec 4 14:20:33] -- Added extension 's' priority 1 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to macro-stdexten [Dec 4 14:20:33] -- Added extension 's' priority 2 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's-NOANSWER' priority 1 to macro-stdexten [Dec 4 14:20:33] -- Added extension 's-NOANSWER' priority 1 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-NOANSWER' priority 2 to macro-stdexten [Dec 4 14:20:33] -- Added extension 's-NOANSWER' priority 2 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 's-BUSY' priority 1 to macro-stdexten [Dec 4 14:20:33] -- Added extension 's-BUSY' priority 1 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's-BUSY' priority 2 to macro-stdexten [Dec 4 14:20:33] -- Added extension 's-BUSY' priority 2 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_s-.' priority 1 to macro-stdexten [Dec 4 14:20:33] -- Added extension '_s-.' priority 1 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 'a' priority 1 to macro-stdexten [Dec 4 14:20:33] -- Added extension 'a' priority 1 to macro-stdexten [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'queues' [Dec 4 14:20:33] -- Registered extension context 'queues' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 'i' priority 1 to queues [Dec 4 14:20:33] -- Added extension 'i' priority 1 to queues [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 'i' priority 2 to queues [Dec 4 14:20:33] -- Added extension 'i' priority 2 to queues [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'anmeldung' [Dec 4 14:20:33] -- Registered extension context 'anmeldung' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to anmeldung [Dec 4 14:20:33] -- Added extension 's' priority 1 to anmeldung [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 2 to anmeldung [Dec 4 14:20:33] -- Added extension 's' priority 2 to anmeldung [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 3 to anmeldung [Dec 4 14:20:33] -- Added extension 's' priority 3 to anmeldung [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 4 to anmeldung [Dec 4 14:20:33] -- Added extension 's' priority 4 to anmeldung [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 5 to anmeldung [Dec 4 14:20:33] -- Added extension 's' priority 5 to anmeldung [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 's' priority 6 to anmeldung [Dec 4 14:20:33] -- Added extension 's' priority 6 to anmeldung [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'capi-in' [Dec 4 14:20:33] -- Registered extension context 'capi-in' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_XXXXXX' priority 1 to capi-in [Dec 4 14:20:33] -- Added extension '_XXXXXX' priority 1 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_XXXXXX' priority 2 to capi-in [Dec 4 14:20:33] -- Added extension '_XXXXXX' priority 2 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_XXXXXX' priority 3 to capi-in [Dec 4 14:20:33] -- Added extension '_XXXXXX' priority 3 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_XXXXXX' priority 4 to capi-in [Dec 4 14:20:33] -- Added extension '_XXXXXX' priority 4 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '_3050' priority 1 to capi-in [Dec 4 14:20:33] -- Added extension '_3050' priority 1 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_3050' priority 2 to capi-in [Dec 4 14:20:33] -- Added extension '_3050' priority 2 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_3050' priority 3 to capi-in [Dec 4 14:20:33] -- Added extension '_3050' priority 3 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_3050' priority 4 to capi-in [Dec 4 14:20:33] -- Added extension '_3050' priority 4 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 't' priority 1 to capi-in [Dec 4 14:20:33] -- Added extension 't' priority 1 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 'i' priority 1 to capi-in [Dec 4 14:20:33] -- Added extension 'i' priority 1 to capi-in [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'capi-out' [Dec 4 14:20:33] -- Registered extension context 'capi-out' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_1XX' priority 1 to capi-out [Dec 4 14:20:33] -- Added extension '_1XX' priority 1 to capi-out [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_1XX' priority 2 to capi-out [Dec 4 14:20:33] -- Added extension '_1XX' priority 2 to capi-out [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_2XX' priority 1 to capi-out [Dec 4 14:20:33] -- Added extension '_2XX' priority 1 to capi-out [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_2XX' priority 2 to capi-out [Dec 4 14:20:33] -- Added extension '_2XX' priority 2 to capi-out [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'hints' [Dec 4 14:20:33] -- Registered extension context 'hints' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 100: SIP/tru [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '100' priority -1 to hints [Dec 4 14:20:33] -- Added extension '100' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 108: SIP/and [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '108' priority -1 to hints [Dec 4 14:20:33] -- Added extension '108' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 115: SIP/omb [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '115' priority -1 to hints [Dec 4 14:20:33] -- Added extension '115' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 116: SIP/usc [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '116' priority -1 to hints [Dec 4 14:20:33] -- Added extension '116' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 120: SIP/fri [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '120' priority -1 to hints [Dec 4 14:20:33] -- Added extension '120' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 124: SIP/leg [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '124' priority -1 to hints [Dec 4 14:20:33] -- Added extension '124' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 127: SIP/rvr [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '127' priority -1 to hints [Dec 4 14:20:33] -- Added extension '127' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 128: SIP/kra [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '128' priority -1 to hints [Dec 4 14:20:33] -- Added extension '128' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 129: SIP/jsc [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '129' priority -1 to hints [Dec 4 14:20:33] -- Added extension '129' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 130: SIP/wac [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '130' priority -1 to hints [Dec 4 14:20:33] -- Added extension '130' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 143: SIP/hil [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '143' priority -1 to hints [Dec 4 14:20:33] -- Added extension '143' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 148: SIP/mum [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '148' priority -1 to hints [Dec 4 14:20:33] -- Added extension '148' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 149: SIP/got [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '149' priority -1 to hints [Dec 4 14:20:33] -- Added extension '149' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 168: SIP/vsc [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '168' priority -1 to hints [Dec 4 14:20:33] -- Added extension '168' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 176: SIP/aba [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '176' priority -1 to hints [Dec 4 14:20:33] -- Added extension '176' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 186: SIP/mag [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '186' priority -1 to hints [Dec 4 14:20:33] -- Added extension '186' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 190: SIP/nol [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '190' priority -1 to hints [Dec 4 14:20:33] -- Added extension '190' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 191: SIP/vsc [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '191' priority -1 to hints [Dec 4 14:20:33] -- Added extension '191' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 199: SIP/emi [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '199' priority -1 to hints [Dec 4 14:20:33] -- Added extension '199' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 227: SIP/wie [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '227' priority -1 to hints [Dec 4 14:20:33] -- Added extension '227' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:2097 ast_add_hint: HINTS: Adding hint 230: SIP/smu [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '230' priority -1 to hints [Dec 4 14:20:33] -- Added extension '230' priority -1 to hints [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'analog' [Dec 4 14:20:33] -- Registered extension context 'analog' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_0.' priority 1 to analog [Dec 4 14:20:33] -- Added extension '_0.' priority 1 to analog [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_0.' priority 2 to analog [Dec 4 14:20:33] -- Added extension '_0.' priority 2 to analog [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 'XXX' priority 1 to analog [Dec 4 14:20:33] -- Added extension 'XXX' priority 1 to analog [Dec 4 14:20:33] DEBUG[12994]: pbx.c:3674 ast_context_create: Registered context 'default' [Dec 4 14:20:33] -- Registered extension context 'default' [Dec 4 14:20:33] -- Including context 'parkedcalls' in context 'default' [Dec 4 14:20:33] -- Including context 'hints' in context 'default' [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension 's' priority 1 to default [Dec 4 14:20:33] -- Added extension 's' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '0' priority 1 to default [Dec 4 14:20:33] -- Added extension '0' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '101' priority 1 to default [Dec 4 14:20:33] -- Added extension '101' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '101' priority 2 to default [Dec 4 14:20:33] -- Added extension '101' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '102' priority 1 to default [Dec 4 14:20:33] -- Added extension '102' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '102' priority 2 to default [Dec 4 14:20:33] -- Added extension '102' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '104' priority 1 to default [Dec 4 14:20:33] -- Added extension '104' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '105' priority 1 to default [Dec 4 14:20:33] -- Added extension '105' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '106' priority 1 to default [Dec 4 14:20:33] -- Added extension '106' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '107' priority 1 to default [Dec 4 14:20:33] -- Added extension '107' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '111' priority 1 to default [Dec 4 14:20:33] -- Added extension '111' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '126' priority 1 to default [Dec 4 14:20:33] -- Added extension '126' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '126' priority 2 to default [Dec 4 14:20:33] -- Added extension '126' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '151' priority 1 to default [Dec 4 14:20:33] -- Added extension '151' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '151' priority 2 to default [Dec 4 14:20:33] -- Added extension '151' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '178' priority 1 to default [Dec 4 14:20:33] -- Added extension '178' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '178' priority 2 to default [Dec 4 14:20:33] -- Added extension '178' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '200' priority 1 to default [Dec 4 14:20:33] -- Added extension '200' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '200' priority 2 to default [Dec 4 14:20:33] -- Added extension '200' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '205' priority 1 to default [Dec 4 14:20:33] -- Added extension '205' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '205' priority 2 to default [Dec 4 14:20:33] -- Added extension '205' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '238' priority 1 to default [Dec 4 14:20:33] -- Added extension '238' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '238' priority 2 to default [Dec 4 14:20:33] -- Added extension '238' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '238' priority 3 to default [Dec 4 14:20:33] -- Added extension '238' priority 3 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '290' priority 1 to default [Dec 4 14:20:33] -- Added extension '290' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '291' priority 1 to default [Dec 4 14:20:33] -- Added extension '291' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '292' priority 1 to default [Dec 4 14:20:33] -- Added extension '292' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '293' priority 1 to default [Dec 4 14:20:33] -- Added extension '293' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '294' priority 1 to default [Dec 4 14:20:33] -- Added extension '294' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '295' priority 1 to default [Dec 4 14:20:33] -- Added extension '295' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '296' priority 1 to default [Dec 4 14:20:33] -- Added extension '296' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '297' priority 1 to default [Dec 4 14:20:33] -- Added extension '297' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '298' priority 1 to default [Dec 4 14:20:33] -- Added extension '298' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '299' priority 1 to default [Dec 4 14:20:33] -- Added extension '299' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4876 ast_add_extension2: Added extension '_0X.' priority 1 to default [Dec 4 14:20:33] -- Added extension '_0X.' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_0X.' priority 2 to default [Dec 4 14:20:33] -- Added extension '_0X.' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension '_0X.' priority 3 to default [Dec 4 14:20:33] -- Added extension '_0X.' priority 3 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension '_#.' priority 1 to default [Dec 4 14:20:33] -- Added extension '_#.' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 'i' priority 1 to default [Dec 4 14:20:33] -- Added extension 'i' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 't' priority 1 to default [Dec 4 14:20:33] -- Added extension 't' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4861 ast_add_extension2: Added extension 'asterisk' priority 1 to default [Dec 4 14:20:33] -- Added extension 'asterisk' priority 1 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 'asterisk' priority 2 to default [Dec 4 14:20:33] -- Added extension 'asterisk' priority 2 to default [Dec 4 14:20:33] DEBUG[12994]: pbx.c:4842 ast_add_extension2: Added extension 'asterisk' priority 3 to default [Dec 4 14:20:33] -- Added extension 'asterisk' priority 3 to default [Dec 4 14:20:33] [pbx_spool.so][Dec 4 14:20:33] => (Outgoing Spool Support) [Dec 4 14:20:33] [pbx_dundi.so][Dec 4 14:20:33] => (Distributed Universal Number Discovery (DUNDi)) [Dec 4 14:20:33] == Parsing '/etc/asterisk/dundi.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/dundi.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] WARNING[12994]: pbx_dundi.c:4584 set_config: Unable to look up host 'etch' [Dec 4 14:20:33] DEBUG[12994]: pbx_dundi.c:422 reset_global_eid: Seeding global EID '00:0c:29:f1:b6:82' from 'eth0' [Dec 4 14:20:33] == Using TOS bits 0 [Dec 4 14:20:33] == DUNDi Ready and Listening on 0.0.0.0 port 4520 [Dec 4 14:20:33] == Registered application 'DUNDiLookup' [Dec 4 14:20:33] == Registered custom function DUNDILOOKUP [Dec 4 14:20:33] [pbx_loopback.so][Dec 4 14:20:33] => (Loopback Switch) [Dec 4 14:20:33] [pbx_realtime.so][Dec 4 14:20:33] => (Realtime Switch) [Dec 4 14:20:33] [pbx_ael.so][Dec 4 14:20:33] => (Asterisk Extension Language Compiler) [Dec 4 14:20:33] WARNING[12994]: pbx.c:3761 ast_merge_contexts_and_delete: Requested contexts didn't get merged [Dec 4 14:20:33] [pbx_functions.so][Dec 4 14:20:33] => (Builtin dialplan functions) [Dec 4 14:20:33] == Registered custom function MD5 [Dec 4 14:20:33] == Registered custom function CHECK_MD5 [Dec 4 14:20:33] == Registered custom function MATH [Dec 4 14:20:33] == Registered custom function GROUP_COUNT [Dec 4 14:20:33] == Registered custom function GROUP_MATCH_COUNT [Dec 4 14:20:33] == Registered custom function GROUP [Dec 4 14:20:33] == Registered custom function GROUP_LIST [Dec 4 14:20:33] == Registered custom function FIELDQTY [Dec 4 14:20:33] == Registered custom function REGEX [Dec 4 14:20:33] == Registered custom function LEN [Dec 4 14:20:33] == Registered custom function STRFTIME [Dec 4 14:20:33] == Registered custom function EVAL [Dec 4 14:20:33] == Registered custom function CDR [Dec 4 14:20:33] == Registered custom function ISNULL [Dec 4 14:20:33] == Registered custom function SET [Dec 4 14:20:33] == Registered custom function EXISTS [Dec 4 14:20:33] == Registered custom function IF [Dec 4 14:20:33] == Registered custom function IFTIME [Dec 4 14:20:33] == Registered custom function ENV [Dec 4 14:20:33] == Registered custom function DB [Dec 4 14:20:33] == Registered custom function DB_EXISTS [Dec 4 14:20:33] == Registered custom function TIMEOUT [Dec 4 14:20:33] == Registered custom function LANGUAGE [Dec 4 14:20:33] == Registered custom function MUSICCLASS [Dec 4 14:20:33] [chan_sip.so][Dec 4 14:20:33] => (Session Initiation Protocol (SIP)) [Dec 4 14:20:33] == Parsing '/etc/asterisk/sip.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/sip.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] -- SIP Seeding peer from astdb: 'snom1' at snom1@10.3.67.149:2051 for 3600 [Dec 4 14:20:33] -- SIP Seeding peer from astdb: 'snom2' at snom2@10.3.67.121:2054 for 3600 [Dec 4 14:20:33] -- SIP Seeding peer from astdb: 'snom3' at snom3@10.3.67.172:2051 for 3600 [Dec 4 14:20:33] == SIP Listening on 0.0.0.0:5060 [Dec 4 14:20:33] == Using TOS bits 16 [Dec 4 14:20:33] == Parsing '/etc/asterisk/sip_notify.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/sip_notify.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'SIP' (Session Initiation Protocol (SIP)) [Dec 4 14:20:33] == Registered channel type 'SIP' (Session Initiation Protocol (SIP)) [Dec 4 14:20:33] == Registered application 'SIPDtmfMode' [Dec 4 14:20:33] == Registered application 'SIPAddHeader' [Dec 4 14:20:33] == Registered application 'SIPGetHeader' [Dec 4 14:20:33] == Registered custom function SIP_HEADER [Dec 4 14:20:33] == Registered custom function SIPPEER [Dec 4 14:20:33] == Registered custom function SIPCHANINFO [Dec 4 14:20:33] == Registered custom function CHECKSIPDOMAIN [Dec 4 14:20:33] == Manager registered action SIPpeers [Dec 4 14:20:33] == Manager registered action SIPshowpeer [Dec 4 14:20:33] [chan_agent.so][Dec 4 14:20:33] => (Agent Proxy Channel) [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'Agent' (Call Agent Proxy Channel) [Dec 4 14:20:33] == Registered channel type 'Agent' (Call Agent Proxy Channel) [Dec 4 14:20:33] == Registered application 'AgentLogin' [Dec 4 14:20:33] == Registered application 'AgentCallbackLogin' [Dec 4 14:20:33] == Registered application 'AgentMonitorOutgoing' [Dec 4 14:20:33] == Manager registered action Agents [Dec 4 14:20:33] == Manager registered action AgentLogoff [Dec 4 14:20:33] == Manager registered action AgentCallbackLogin [Dec 4 14:20:33] == Parsing '/etc/asterisk/agents.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/agents.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] DEBUG[12994]: chan_agent.c:2356 reload_agents: Reload Agent: 129 on 105;snom1 [Dec 4 14:20:33] == Setting global variable 'AGENTBYCALLERID_snom1' to '129' [Dec 4 14:20:33] DEBUG[12994]: chan_agent.c:2356 reload_agents: Reload Agent: 130 on 106;snom2 [Dec 4 14:20:33] == Setting global variable 'AGENTBYCALLERID_snom2' to '130' [Dec 4 14:20:33] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Agent/129 - state 1 (Not in use) [Dec 4 14:20:33] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Agent/130 - state 1 (Not in use) [Dec 4 14:20:33] NOTICE[12994]: chan_agent.c:2373 reload_agents: Agents successfully reloaded from database. [Dec 4 14:20:33] [skipping chan_mgcp.so] [Dec 4 14:20:33] [chan_iax2.so][Dec 4 14:20:33] => (Inter Asterisk eXchange (Ver 2)) [Dec 4 14:20:33] == Registered custom function IAXPEER [Dec 4 14:20:33] WARNING[12994]: chan_iax2.c:9697 load_module: Unable to open IAX timing interface: No such file or directory [Dec 4 14:20:33] == Registered application 'IAX2Provision' [Dec 4 14:20:33] == Manager registered action IAXpeers [Dec 4 14:20:33] == Manager registered action IAXnetstats [Dec 4 14:20:33] == Parsing '/etc/asterisk/iax.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/iax.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] == Using TOS bits 16 [Dec 4 14:20:33] == Binding IAX2 to default address 0.0.0.0:4569 [Dec 4 14:20:33] -- doing lookup for '216.207.245.47' [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) [Dec 4 14:20:33] == Registered channel type 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) [Dec 4 14:20:33] == IAX Ready and Listening [Dec 4 14:20:33] == Parsing '/etc/asterisk/iaxprov.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/iaxprov.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] -- Loaded provisioning template 'default' [Dec 4 14:20:33] [chan_local.so][Dec 4 14:20:33] => (Local Proxy Channel) [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'Local' (Local Proxy Channel Driver) [Dec 4 14:20:33] == Registered channel type 'Local' (Local Proxy Channel Driver) [Dec 4 14:20:33] [skipping chan_skinny.so] [Dec 4 14:20:33] [chan_features.so][Dec 4 14:20:33] => (Feature Proxy Channel) [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'Feature' (Feature Proxy Channel Driver) [Dec 4 14:20:33] == Registered channel type 'Feature' (Feature Proxy Channel Driver) [Dec 4 14:20:33] [chan_oss.so][Dec 4 14:20:33] => (OSS Console Channel Driver) [Dec 4 14:20:33] == Parsing '/etc/asterisk/oss.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/oss.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'Console' (OSS Console Channel Driver) [Dec 4 14:20:33] == Registered channel type 'Console' (OSS Console Channel Driver) [Dec 4 14:20:33] [chan_phone.so][Dec 4 14:20:33] => (Linux Telephony API Support) [Dec 4 14:20:33] == Parsing '/etc/asterisk/phone.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/phone.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] DEBUG[12994]: channel.c:344 ast_channel_register: Registered handler for 'Phone' (Standard Linux Telephony API Driver) [Dec 4 14:20:33] == Registered channel type 'Phone' (Standard Linux Telephony API Driver) [Dec 4 14:20:33] [skipping chan_alsa.so] [Dec 4 14:20:33] [skipping chan_zap.so] [Dec 4 14:20:33] [skipping chan_capi.so] [Dec 4 14:20:33] [skipping chan_misdn.so] [Dec 4 14:20:33] [skipping chan_h323.so] [Dec 4 14:20:33] [app_parkandannounce.so][Dec 4 14:20:33] => (Call Parking and Announce Application) [Dec 4 14:20:33] == Registered application 'ParkAndAnnounce' [Dec 4 14:20:33] [skipping res_config_odbc.so] [Dec 4 14:20:33] [skipping chan_mgcp.so] [Dec 4 14:20:33] [skipping chan_skinny.so] [Dec 4 14:20:33] [skipping chan_alsa.so] [Dec 4 14:20:33] [skipping chan_zap.so] [Dec 4 14:20:33] [app_dial.so][Dec 4 14:20:33] => (Dialing Application) [Dec 4 14:20:33] == Registered application 'Dial' [Dec 4 14:20:33] == Registered application 'RetryDial' [Dec 4 14:20:33] [app_playback.so][Dec 4 14:20:33] => (Sound File Playback Application) [Dec 4 14:20:33] == Registered application 'Playback' [Dec 4 14:20:33] [app_voicemail.so][Dec 4 14:20:33] => (Comedian Mail (Voicemail System)) [Dec 4 14:20:33] == Registered application 'VoiceMail' [Dec 4 14:20:33] == Registered application 'VoiceMailMain' [Dec 4 14:20:33] == Registered application 'MailboxExists' [Dec 4 14:20:33] == Registered application 'VMAuthenticate' [Dec 4 14:20:33] == Parsing '/etc/asterisk/voicemail.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/voicemail.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] DEBUG[12994]: app_voicemail.c:6098 load_config: VM_CID Internal context string: intern [Dec 4 14:20:33] DEBUG[12994]: app_voicemail.c:6106 load_config: VM_CID Internal context 0: intern [Dec 4 14:20:33] DEBUG[12994]: app_voicemail.c:6119 load_config: VM Operator break disabled globally [Dec 4 14:20:33] DEBUG[12994]: app_voicemail.c:6131 load_config: Send Voicemail msg disabled globally [Dec 4 14:20:33] DEBUG[12994]: app_voicemail.c:6137 load_config: ENVELOPE before msg enabled globally [Dec 4 14:20:33] [app_directory.so][Dec 4 14:20:33] => (Extension Directory) [Dec 4 14:20:33] == Registered application 'Directory' [Dec 4 14:20:33] [app_mp3.so][Dec 4 14:20:33] => (Silly MP3 Application) [Dec 4 14:20:33] == Registered application 'MP3Player' [Dec 4 14:20:33] [app_system.so][Dec 4 14:20:33] => (Generic System() application) [Dec 4 14:20:33] == Registered application 'TrySystem' [Dec 4 14:20:33] == Registered application 'System' [Dec 4 14:20:33] [app_echo.so][Dec 4 14:20:33] => (Simple Echo Application) [Dec 4 14:20:33] == Registered application 'Echo' [Dec 4 14:20:33] [app_record.so][Dec 4 14:20:33] => (Trivial Record Application) [Dec 4 14:20:33] == Registered application 'Record' [Dec 4 14:20:33] [app_image.so][Dec 4 14:20:33] => (Image Transmission Application) [Dec 4 14:20:33] == Registered application 'SendImage' [Dec 4 14:20:33] [app_url.so][Dec 4 14:20:33] => (Send URL Applications) [Dec 4 14:20:33] == Registered application 'SendURL' [Dec 4 14:20:33] [app_disa.so][Dec 4 14:20:33] => (DISA (Direct Inward System Access) Application) [Dec 4 14:20:33] == Registered application 'DISA' [Dec 4 14:20:33] [app_adsiprog.so][Dec 4 14:20:33] => (Asterisk ADSI Programming Application) [Dec 4 14:20:33] == Registered application 'ADSIProg' [Dec 4 14:20:33] [app_getcpeid.so][Dec 4 14:20:33] => (Get ADSI CPE ID) [Dec 4 14:20:33] == Registered application 'GetCPEID' [Dec 4 14:20:33] [app_milliwatt.so][Dec 4 14:20:33] => (Digital Milliwatt (mu-law) Test Application) [Dec 4 14:20:33] == Registered application 'Milliwatt' [Dec 4 14:20:33] [app_zapateller.so][Dec 4 14:20:33] => (Block Telemarketers with Special Information Tone) [Dec 4 14:20:33] == Registered application 'Zapateller' [Dec 4 14:20:33] [app_setcallerid.so][Dec 4 14:20:33] => (Set CallerID Application) [Dec 4 14:20:33] == Registered application 'SetCallerPres' [Dec 4 14:20:33] == Registered application 'SetCallerID' [Dec 4 14:20:33] [app_festival.so][Dec 4 14:20:33] => (Simple Festival Interface) [Dec 4 14:20:33] == Registered application 'Festival' [Dec 4 14:20:33] [app_queue.so][Dec 4 14:20:33] => (True Call Queueing) [Dec 4 14:20:33] == Registered application 'Queue' [Dec 4 14:20:33] == Manager registered action Queues [Dec 4 14:20:33] == Manager registered action QueueStatus [Dec 4 14:20:33] == Manager registered action QueueAdd [Dec 4 14:20:33] == Manager registered action QueueRemove [Dec 4 14:20:33] == Manager registered action QueuePause [Dec 4 14:20:33] == Registered application 'AddQueueMember' [Dec 4 14:20:33] == Registered application 'RemoveQueueMember' [Dec 4 14:20:33] == Registered application 'PauseQueueMember' [Dec 4 14:20:33] == Registered application 'UnpauseQueueMember' [Dec 4 14:20:33] == Registered custom function QUEUEAGENTCOUNT [Dec 4 14:20:33] == Parsing '/etc/asterisk/queues.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/queues.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/165 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/155 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/157 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/183 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/190 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/192 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/166 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/180 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/135 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/107 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/133 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/142 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/145 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/163 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/187 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/124 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/129 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/130 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding Agent/168 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom1 [Dec 4 14:20:33] DEBUG[12994]: app_queue.c:658 add_to_interfaces: Adding SIP/snom1 to the list of interfaces that make up all of our queue members. [Dec 4 14:20:33] DEBUG[12994]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom1 [Dec 4 14:20:33] [app_senddtmf.so][Dec 4 14:20:33] => (Send DTMF digits Application) [Dec 4 14:20:33] == Manager registered action playDTMF [Dec 4 14:20:33] == Registered application 'SendDTMF' [Dec 4 14:20:33] [app_lookupcidname.so][Dec 4 14:20:33] => (Look up CallerID Name from local database) [Dec 4 14:20:33] == Registered application 'LookupCIDName' [Dec 4 14:20:33] [app_setcidname.so][Dec 4 14:20:33] => (Set CallerID Name) [Dec 4 14:20:33] == Registered application 'SetCIDName' [Dec 4 14:20:33] [app_authenticate.so][Dec 4 14:20:33] => (Authentication Application) [Dec 4 14:20:33] == Registered application 'Authenticate' [Dec 4 14:20:33] [app_macro.so][Dec 4 14:20:33] => (Extension Macros) [Dec 4 14:20:33] == Registered application 'MacroExit' [Dec 4 14:20:33] == Registered application 'MacroIf' [Dec 4 14:20:33] == Registered application 'Macro' [Dec 4 14:20:33] [app_lookupblacklist.so][Dec 4 14:20:33] => (Look up Caller*ID name/number from blacklist database) [Dec 4 14:20:33] == Registered application 'LookupBlacklist' [Dec 4 14:20:33] [app_softhangup.so][Dec 4 14:20:33] => (Hangs up the requested channel) [Dec 4 14:20:33] == Registered application 'SoftHangup' [Dec 4 14:20:33] [app_hasnewvoicemail.so][Dec 4 14:20:33] => (Indicator for whether a voice mailbox has messages in a given folder.) [Dec 4 14:20:33] == Registered custom function VMCOUNT [Dec 4 14:20:33] == Registered application 'HasVoicemail' [Dec 4 14:20:33] == Registered application 'HasNewVoicemail' [Dec 4 14:20:33] [app_waitforring.so][Dec 4 14:20:33] => (Waits until first ring after time) [Dec 4 14:20:33] == Registered application 'WaitForRing' [Dec 4 14:20:33] [app_privacy.so][Dec 4 14:20:33] => (Require phone number to be entered, if no CallerID sent) [Dec 4 14:20:33] == Registered application 'PrivacyManager' [Dec 4 14:20:33] [app_db.so][Dec 4 14:20:33] => (Database Access Functions) [Dec 4 14:20:33] == Registered application 'DBget' [Dec 4 14:20:33] == Registered application 'DBput' [Dec 4 14:20:33] == Registered application 'DBdel' [Dec 4 14:20:33] == Registered application 'DBdeltree' [Dec 4 14:20:33] [app_chanisavail.so][Dec 4 14:20:33] => (Check channel availability) [Dec 4 14:20:33] == Registered application 'ChanIsAvail' [Dec 4 14:20:33] [app_enumlookup.so][Dec 4 14:20:33] => (ENUM Lookup) [Dec 4 14:20:33] == Registered application 'EnumLookup' [Dec 4 14:20:33] == Parsing '/etc/asterisk/enum.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/enum.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] [app_transfer.so][Dec 4 14:20:33] => (Transfer) [Dec 4 14:20:33] == Registered application 'Transfer' [Dec 4 14:20:33] [app_setcidnum.so][Dec 4 14:20:33] => (Set CallerID Number) [Dec 4 14:20:33] == Registered application 'SetCIDNum' [Dec 4 14:20:33] [app_cdr.so][Dec 4 14:20:33] => (Tell Asterisk to not maintain a CDR for the current call) [Dec 4 14:20:33] == Registered application 'NoCDR' [Dec 4 14:20:33] [app_setcdruserfield.so][Dec 4 14:20:33] => (CDR user field apps) [Dec 4 14:20:33] == Registered application 'SetCDRUserField' [Dec 4 14:20:33] == Registered application 'AppendCDRUserField' [Dec 4 14:20:33] == Manager registered action SetCDRUserField [Dec 4 14:20:33] [app_sayunixtime.so][Dec 4 14:20:33] => (Say time) [Dec 4 14:20:33] == Registered application 'SayUnixTime' [Dec 4 14:20:33] == Registered application 'DateTime' [Dec 4 14:20:33] [app_cut.so][Dec 4 14:20:33] => (Cut out information from a string) [Dec 4 14:20:33] == Registered custom function CUT [Dec 4 14:20:33] == Registered custom function SORT [Dec 4 14:20:33] == Registered application 'Sort' [Dec 4 14:20:33] == Registered application 'Cut' [Dec 4 14:20:33] [app_read.so][Dec 4 14:20:33] => (Read Variable Application) [Dec 4 14:20:33] == Registered application 'Read' [Dec 4 14:20:33] [app_groupcount.so][Dec 4 14:20:33] => (Group Management Routines) [Dec 4 14:20:33] == Registered application 'GetGroupCount' [Dec 4 14:20:33] == Registered application 'SetGroup' [Dec 4 14:20:33] == Registered application 'CheckGroup' [Dec 4 14:20:33] == Registered application 'GetGroupMatchCount' [Dec 4 14:20:33] [app_random.so][Dec 4 14:20:33] => (Random goto) [Dec 4 14:20:33] == Registered application 'Random' [Dec 4 14:20:33] [app_ices.so][Dec 4 14:20:33] => (Encode and Stream via icecast and ices) [Dec 4 14:20:33] == Registered application 'ICES' [Dec 4 14:20:33] [app_eval.so][Dec 4 14:20:33] => (Reevaluates strings) [Dec 4 14:20:33] == Registered application 'Eval' [Dec 4 14:20:33] [app_nbscat.so][Dec 4 14:20:33] => (Silly NBS Stream Application) [Dec 4 14:20:33] == Registered application 'NBScat' [Dec 4 14:20:33] [app_sendtext.so][Dec 4 14:20:33] => (Send Text Applications) [Dec 4 14:20:33] == Registered application 'SendText' [Dec 4 14:20:33] [app_exec.so][Dec 4 14:20:33] => (Executes applications) [Dec 4 14:20:33] == Registered application 'Exec' [Dec 4 14:20:33] [app_controlplayback.so][Dec 4 14:20:33] => (Control Playback Application) [Dec 4 14:20:33] == Registered application 'ControlPlayback' [Dec 4 14:20:33] [app_txtcidname.so][Dec 4 14:20:33] => (TXTCIDName) [Dec 4 14:20:33] == Registered application 'TXTCIDName' [Dec 4 14:20:33] [app_alarmreceiver.so][Dec 4 14:20:33] => (Alarm Receiver for Asterisk) [Dec 4 14:20:33] == Parsing '/etc/asterisk/alarmreceiver.conf': [Dec 4 14:20:33] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/alarmreceiver.conf [Dec 4 14:20:33] Found [Dec 4 14:20:33] == Registered application 'AlarmReceiver' [Dec 4 14:20:33] [app_talkdetect.so][Dec 4 14:20:33] => (Playback with Talk Detection) [Dec 4 14:20:33] == Registered application 'BackgroundDetect' [Dec 4 14:20:33] [app_waitforsilence.so][Dec 4 14:20:33] => (Wait For Silence) [Dec 4 14:20:33] == Registered application 'WaitForSilence' [Dec 4 14:20:33] [app_userevent.so][Dec 4 14:20:33] => (Custom User Event Application) [Dec 4 14:20:33] == Registered application 'UserEvent' [Dec 4 14:20:33] [app_verbose.so][Dec 4 14:20:33] => (Send verbose output) [Dec 4 14:20:33] == Registered application 'Verbose' [Dec 4 14:20:33] [app_test.so][Dec 4 14:20:34] => (Interface Test Application) [Dec 4 14:20:34] == Registered application 'TestClient' [Dec 4 14:20:34] == Registered application 'TestServer' [Dec 4 14:20:34] [app_forkcdr.so][Dec 4 14:20:34] => (Fork The CDR into 2 separate entities.) [Dec 4 14:20:34] == Registered application 'ForkCDR' [Dec 4 14:20:34] [app_math.so][Dec 4 14:20:34] => (Basic Math Functions) [Dec 4 14:20:34] == Registered application 'Math' [Dec 4 14:20:34] [app_realtime.so][Dec 4 14:20:34] => (Realtime Data Lookup/Rewrite) [Dec 4 14:20:34] == Registered application 'RealTimeUpdate' [Dec 4 14:20:34] == Registered application 'RealTime' [Dec 4 14:20:34] [app_dumpchan.so][Dec 4 14:20:34] => (Dump Info About The Calling Channel) [Dec 4 14:20:34] == Registered application 'DumpChan' [Dec 4 14:20:34] [app_externalivr.so][Dec 4 14:20:34] => (External IVR Interface Application) [Dec 4 14:20:34] == Registered application 'ExternalIVR' [Dec 4 14:20:34] [app_while.so][Dec 4 14:20:34] => (While Loops and Conditional Execution) [Dec 4 14:20:34] == Registered application 'While' [Dec 4 14:20:34] == Registered application 'ExecIf' [Dec 4 14:20:34] == Registered application 'EndWhile' [Dec 4 14:20:34] [app_setrdnis.so][Dec 4 14:20:34] => (Set RDNIS Number) [Dec 4 14:20:34] == Registered application 'SetRDNIS' [Dec 4 14:20:34] [app_md5.so][Dec 4 14:20:34] => (MD5 checksum applications) [Dec 4 14:20:34] == Registered application 'MD5Check' [Dec 4 14:20:34] == Registered application 'MD5' [Dec 4 14:20:34] [app_readfile.so][Dec 4 14:20:34] => (Stores output of file into a variable) [Dec 4 14:20:34] == Registered application 'ReadFile' [Dec 4 14:20:34] [app_chanspy.so][Dec 4 14:20:34] => (Listen to the audio of an active channel ) [Dec 4 14:20:34] == Registered application 'ChanSpy' [Dec 4 14:20:34] [app_dictate.so][Dec 4 14:20:34] => (Virtual Dictation Machine) [Dec 4 14:20:34] == Registered application 'Dictate' [Dec 4 14:20:34] [app_stack.so][Dec 4 14:20:34] => (Stack Routines) [Dec 4 14:20:34] == Registered application 'StackPop' [Dec 4 14:20:34] == Registered application 'Return' [Dec 4 14:20:34] == Registered application 'GosubIf' [Dec 4 14:20:34] == Registered application 'Gosub' [Dec 4 14:20:34] [app_settransfercapability.so][Dec 4 14:20:34] => (Set ISDN Transfer Capability) [Dec 4 14:20:34] == Registered application 'SetTransferCapability' [Dec 4 14:20:34] [skipping res_config_mysql.so] [Dec 4 14:20:34] [app_mixmonitor.so][Dec 4 14:20:34] => (Mixed Audio Monitoring Application) [Dec 4 14:20:34] == Registered application 'MixMonitor' [Dec 4 14:20:34] [app_zapras.so][Dec 4 14:20:34] => (Zap RAS Application) [Dec 4 14:20:34] == Registered application 'ZapRAS' [Dec 4 14:20:34] [skipping cdr_addon_mysql.so] [Dec 4 14:20:34] [app_meetme.so][Dec 4 14:20:34] => (MeetMe conference bridge) [Dec 4 14:20:34] == Parsing '/etc/asterisk/meetme.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/meetme.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] == Registered application 'MeetMeAdmin' [Dec 4 14:20:34] == Registered application 'MeetMeCount' [Dec 4 14:20:34] == Registered application 'MeetMe' [Dec 4 14:20:34] [app_flash.so][Dec 4 14:20:34] => (Flash zap trunk application) [Dec 4 14:20:34] == Registered application 'Flash' [Dec 4 14:20:34] [app_zapbarge.so][Dec 4 14:20:34] => (Barge in on Zap channel application) [Dec 4 14:20:34] == Registered application 'ZapBarge' [Dec 4 14:20:34] [app_zapscan.so][Dec 4 14:20:34] => (Scan Zap channels application) [Dec 4 14:20:34] == Registered application 'ZapScan' [Dec 4 14:20:34] [app_page.so][Dec 4 14:20:34] => (Page Multiple Phones) [Dec 4 14:20:34] == Registered application 'Page' [Dec 4 14:20:34] [app_curl.so][Dec 4 14:20:34] => (Load external URL) [Dec 4 14:20:34] == Registered custom function CURL [Dec 4 14:20:34] == Registered application 'Curl' [Dec 4 14:20:34] [app_sms.so][Dec 4 14:20:34] => (SMS/PSTN handler) [Dec 4 14:20:34] == Registered application 'SMS' [Dec 4 14:20:34] [codec_speex.so][Dec 4 14:20:34] => (Speex/PCM16 (signed linear) Codec Translator) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- CODEC SPEEX: Setting Quality to 3 [Dec 4 14:20:34] -- CODEC SPEEX: Setting Complexity to 2 [Dec 4 14:20:34] -- CODEC SPEEX: Perceptual Enhancement Mode. [on] [Dec 4 14:20:34] -- CODEC SPEEX: VAD Mode. [on] [Dec 4 14:20:34] -- CODEC SPEEX: VBR Mode. [on] [Dec 4 14:20:34] -- CODEC SPEEX: Disabling ABR [Dec 4 14:20:34] -- CODEC SPEEX: Setting VBR Quality to 4.000000 [Dec 4 14:20:34] -- CODEC SPEEX: DTX Mode. [off] [Dec 4 14:20:34] -- CODEC SPEEX: Preprocessing. [off] [Dec 4 14:20:34] -- CODEC SPEEX: Preprocessor VAD. [off] [Dec 4 14:20:34] -- CODEC SPEEX: Preprocessor AGC. [off] [Dec 4 14:20:34] -- CODEC SPEEX: Setting preprocessor AGC Level to 8000.000000 [Dec 4 14:20:34] -- CODEC SPEEX: Preprocessor Denoise. [off] [Dec 4 14:20:34] -- CODEC SPEEX: Preprocessor Dereverb. [off] [Dec 4 14:20:34] -- CODEC SPEEX: Setting preprocessor Dereverb Decay to 0.400000 [Dec 4 14:20:34] -- CODEC SPEEX: Setting preprocessor Dereverb Level to 0.300000 [Dec 4 14:20:34] == Registered translator 'speextolin' from format speex to slin, cost 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] == Registered translator 'lintospeex' from format slin to speex, cost 42 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] [codec_gsm.so][Dec 4 14:20:34] => (GSM/PCM16 (signed linear) Codec Translator) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- codec_gsm: using generic PLC [Dec 4 14:20:34] == Registered translator 'gsmtolin' from format gsm to slin, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] == Registered translator 'lintogsm' from format slin to gsm, cost 8 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] [codec_lpc10.so][Dec 4 14:20:34] => (LPC10 2.4kbps (signed linear) Voice Coder) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- codec_lpc10: using generic PLC [Dec 4 14:20:34] == Registered translator 'lpc10tolin' from format lpc10 to slin, cost 9 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] == Registered translator 'lintolpc10' from format slin to lpc10, cost 14 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] [codec_adpcm.so][Dec 4 14:20:34] => (Adaptive Differential PCM Coder/Decoder) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- codec_adpcm: using generic PLC [Dec 4 14:20:34] == Registered translator 'adpcmtolin' from format adpcm to slin, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] == Registered translator 'lintoadpcm' from format slin to adpcm, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] [codec_ulaw.so][Dec 4 14:20:34] => (Mu-law Coder/Decoder) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- codec_ulaw: using generic PLC [Dec 4 14:20:34] == Registered translator 'ulawtolin' from format ulaw to slin, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] == Registered translator 'lintoulaw' from format slin to ulaw, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] [codec_alaw.so][Dec 4 14:20:34] => (A-law Coder/Decoder) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- codec_alaw: using generic PLC [Dec 4 14:20:34] == Registered translator 'alawtolin' from format alaw to slin, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] == Registered translator 'lintoalaw' from format slin to alaw, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] [codec_a_mu.so][Dec 4 14:20:34] => (A-law and Mulaw direct Coder/Decoder) [Dec 4 14:20:34] == Registered translator 'alawtoulaw' from format alaw to ulaw, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to g723, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 3 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 16 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 44 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] == Registered translator 'ulawtoalaw' from format ulaw to alaw, cost 1 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to g723, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 3 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 16 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 44 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] [codec_g726.so][Dec 4 14:20:34] => (ITU G.726-32kbps G726 Transcoder) [Dec 4 14:20:34] == Parsing '/etc/asterisk/codecs.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/codecs.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] -- codec_g726: using generic PLC [Dec 4 14:20:34] == Registered translator 'g726tolin' from format g726 to slin, cost 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to g723, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 3 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 16 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 44 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from ulaw to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from ulaw to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 48 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] == Registered translator 'lintog726' from format slin to g726, cost 7 [Dec 4 14:20:34] DEBUG[12994]: translate.c:278 rebuild_matrix: Resetting translation matrix [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 8 cost path from g723 to ulaw, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from g723 to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from gsm to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 8 cost path from gsm to ulaw, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from gsm to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to g723, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to ulaw, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 3 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 16 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 44 cost path from unknown to unknown, via 2 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 8 cost path from unknown to ulaw, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from ulaw to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from ulaw to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 48 cost path from ulaw to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 9 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 2 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 8 cost path from unknown to ulaw, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 15 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 43 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 17 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 16 cost path from unknown to ulaw, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 10 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 51 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 14 cost path from unknown to g723, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to gsm, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 13 cost path from unknown to ulaw, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 7 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] DEBUG[12994]: translate.c:322 rebuild_matrix: Discovered 20 cost path from unknown to unknown, via 6 [Dec 4 14:20:34] [format_gsm.so][Dec 4 14:20:34] => (Raw GSM data) [Dec 4 14:20:34] == Registered file format gsm, extension(s) gsm [Dec 4 14:20:34] [format_wav.so][Dec 4 14:20:34] => (Microsoft WAV format (8000hz Signed Linear)) [Dec 4 14:20:34] == Registered file format wav, extension(s) wav [Dec 4 14:20:34] [format_wav_gsm.so][Dec 4 14:20:34] => (Microsoft WAV format (Proprietary GSM)) [Dec 4 14:20:34] == Registered file format wav49, extension(s) WAV|wav49 [Dec 4 14:20:34] [format_vox.so][Dec 4 14:20:34] => (Dialogic VOX (ADPCM) File Format) [Dec 4 14:20:34] == Registered file format vox, extension(s) vox [Dec 4 14:20:34] [format_pcm.so][Dec 4 14:20:34] => (Raw uLaw 8khz Audio support (PCM)) [Dec 4 14:20:34] == Registered file format pcm, extension(s) pcm|ulaw|ul|mu [Dec 4 14:20:34] [format_g729.so][Dec 4 14:20:34] => (Raw G729 data) [Dec 4 14:20:34] == Registered file format g729, extension(s) g729 [Dec 4 14:20:34] [format_pcm_alaw.so][Dec 4 14:20:34] => (Raw aLaw 8khz PCM Audio support) [Dec 4 14:20:34] == Registered file format alaw, extension(s) alaw|al [Dec 4 14:20:34] [format_h263.so][Dec 4 14:20:34] => (Raw h263 data) [Dec 4 14:20:34] == Registered file format h263, extension(s) h263 [Dec 4 14:20:34] [format_g726.so][Dec 4 14:20:34] => (Raw G.726 (16/24/32/40kbps) data) [Dec 4 14:20:34] == Registered file format g726-40, extension(s) g726-40 [Dec 4 14:20:34] == Registered file format g726-32, extension(s) g726-32 [Dec 4 14:20:34] == Registered file format g726-24, extension(s) g726-24 [Dec 4 14:20:34] == Registered file format g726-16, extension(s) g726-16 [Dec 4 14:20:34] [format_au.so][Dec 4 14:20:34] => (Sun Microsystems AU format (signed linear)) [Dec 4 14:20:34] == Registered file format au, extension(s) au [Dec 4 14:20:34] [format_ilbc.so][Dec 4 14:20:34] => (Raw iLBC data) [Dec 4 14:20:34] == Registered file format iLBC, extension(s) ilbc [Dec 4 14:20:34] [format_sln.so][Dec 4 14:20:34] => (Raw Signed Linear Audio support (SLN)) [Dec 4 14:20:34] == Registered file format sln, extension(s) sln|raw [Dec 4 14:20:34] [format_jpeg.so][Dec 4 14:20:34] => (JPEG (Joint Picture Experts Group) Image Format) [Dec 4 14:20:34] == Registered format 'jpg' (JPEG (Joint Picture Experts Group)) [Dec 4 14:20:34] [format_g723.so][Dec 4 14:20:34] => (G.723.1 Simple Timestamp File Format) [Dec 4 14:20:34] == Registered file format g723sf, extension(s) g723|g723sf [Dec 4 14:20:34] [format_ogg_vorbis.so][Dec 4 14:20:34] => (OGG/Vorbis audio) [Dec 4 14:20:34] == Registered file format ogg_vorbis, extension(s) ogg [Dec 4 14:20:34] [cdr_csv.so][Dec 4 14:20:34] => (Comma Separated Values CDR Backend) [Dec 4 14:20:34] [cdr_manager.so][Dec 4 14:20:34] => (Asterisk Call Manager CDR Backend) [Dec 4 14:20:34] == Parsing '/etc/asterisk/cdr_manager.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/cdr_manager.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] [cdr_custom.so][Dec 4 14:20:34] => (Customizable Comma Separated Values CDR Backend) [Dec 4 14:20:34] == Parsing '/etc/asterisk/cdr_custom.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/cdr_custom.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] [cdr_odbc.so][Dec 4 14:20:34] => (ODBC CDR Backend) [Dec 4 14:20:34] == Parsing '/etc/asterisk/cdr_odbc.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/cdr_odbc.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] [skipping cdr_pgsql.so] [Dec 4 14:20:34] [skipping cdr_sqlite.so] [Dec 4 14:20:34] [func_array.so][Dec 4 14:20:34] => (String handling dialplan functions) [Dec 4 14:20:34] == Registered custom function ARRAY [Dec 4 14:20:34] [func_callerid.so][Dec 4 14:20:34] => (Caller ID related dialplan function) [Dec 4 14:20:34] == Registered custom function CALLERID [Dec 4 14:20:34] [func_enum.so][Dec 4 14:20:34] => (ENUM Related Functions) [Dec 4 14:20:34] == Registered custom function ENUMLOOKUP [Dec 4 14:20:34] == Registered custom function TXTCIDNAME [Dec 4 14:20:34] [func_odbc.so][Dec 4 14:20:34] => (ODBC lookups) [Dec 4 14:20:34] == Parsing '/etc/asterisk/func_odbc.conf': [Dec 4 14:20:34] DEBUG[12994]: config.c:598 config_text_file_load: Parsing /etc/asterisk/func_odbc.conf [Dec 4 14:20:34] Found [Dec 4 14:20:34] == Registered custom function ODBC_SQL [Dec 4 14:20:34] == Registered custom function ODBC_ANTIGF [Dec 4 14:20:34] == Registered custom function ODBC_PRESENCE [Dec 4 14:20:34] == Registered custom function SQL_ESC [Dec 4 14:20:34] [func_uri.so][Dec 4 14:20:34] => (URI encode/decode functions) [Dec 4 14:20:34] == Registered custom function URIDECODE [Dec 4 14:20:34] == Registered custom function URIENCODE [Dec 4 14:20:34] [skipping chan_capi.so] [Dec 4 14:20:34] [app_addon_sql_mysql.so][Dec 4 14:20:34] => (Simple Mysql Interface) [Dec 4 14:20:34] == Registered application 'MYSQL' [Dec 4 14:20:34] [app_saycountpl.so][Dec 4 14:20:34] => (Say polish counting words) [Dec 4 14:20:34] == Registered application 'SayCountPL' [Dec 4 14:20:34] [skipping chan_misdn.so] [Dec 4 14:20:34] [skipping chan_h323.so] [Dec 4 14:20:34] Asterisk Ready. ]1;Asterisk]2;Asterisk Console on 'etch' (pid 12994)*CLI> set verbose 4 Verbosity was 5 and is now 4 *CLI> set debug 4 Core debug was 5 and is now 4 *CLI> sip debug SIP Debugging enabled *CLI> [Dec 4 14:20:41] <-- SIP read from 10.3.67.172:2051: INVITE sip:111@dyn-195.intranet.gonicus.de;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-cw12rg41hgcc;rport From: "leger" ;tag=fon33qim5m To: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 473 v=0 o=root 1586199921 1586199921 IN IP4 10.3.67.172 s=call c=IN IP4 10.3.67.172 t=0 0 m=audio 65464 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:qec5lVtP1Yzrpd4owTxcNmHIHFZ/xcuK02uHpOV6 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: INVITE sip:111@dyn-195.intranet.gonicus.de;user=phone SIP/2.0 (61) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-cw12rg41hgcc;rport (67) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "leger" ;tag=fon33qim5m (68) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: (52) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 (55) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 1 INVITE (14) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Contact: ;flow-id=1 (61) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: User-Agent: snom360/6.5.2 (25) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: Accept: application/sdp (23) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 15: Min-SE: 90 (10) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 16: Content-Type: application/sdp (29) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 17: Content-Length: 473 (19) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 18: (0) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: v=0 (3) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: o=root 1586199921 1586199921 IN IP4 10.3.67.172 (47) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: s=call (6) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: c=IN IP4 10.3.67.172 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: t=0 0 (5) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: m=audio 65464 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:qec5lVtP1Yzrpd4owTxcNmHIHFZ/xcuK02uHpOV6 (82) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=ptime:20 (10) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=encryption:optional (21) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=sendrecv (10) [Dec 4 14:20:41] --- (18 headers 19 lines) --- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 - INVITE (With RTP) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:11268 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1014 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -timer- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1032 parse_sip_options: Matched SIP option: timer [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -100rel- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1032 parse_sip_options: Matched SIP option: 100rel [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -replaces- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1032 parse_sip_options: Matched SIP option: replaces [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -callerid- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1037 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1043 parse_sip_options: * SIP extension value: 7 for call 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 [Dec 4 14:20:41] Using INVITE request as basis request - 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 [Dec 4 14:20:41] Sending to 10.3.67.172 : 2051 (NAT) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:7265 check_user_full: Setting NAT on RTP to 0 [Dec 4 14:20:41] Reliably Transmitting (no NAT) to 10.3.67.172:2051: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-cw12rg41hgcc;received=10.3.67.172;rport=2051 From: "leger" ;tag=fon33qim5m To: ;tag=as461dab67 Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="16e4e5e0" Content-Length: 0 --- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1306 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #7 [Dec 4 14:20:41] Scheduling destruction of call '3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69' in 15000 ms [Dec 4 14:20:41] Found user 'snom3' [Dec 4 14:20:41] <-- SIP read from 10.3.67.172:2051: ACK sip:111@dyn-195.intranet.gonicus.de;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-cw12rg41hgcc;rport From: "leger" ;tag=fon33qim5m To: ;tag=as461dab67 Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: ACK sip:111@dyn-195.intranet.gonicus.de;user=phone SIP/2.0 (58) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-cw12rg41hgcc;rport (67) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "leger" ;tag=fon33qim5m (68) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=as461dab67 (67) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 (55) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 1 ACK (11) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Contact: ;flow-id=1 (61) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Content-Length: 0 (17) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: (0) [Dec 4 14:20:41] --- (9 headers 0 lines) --- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:11268 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1402 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #7 [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:1414 __sip_ack: Stopping retransmission on '3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69' of Response 1: Match Found [Dec 4 14:20:41] <-- SIP read from 10.3.67.172:2051: INVITE sip:111@dyn-195.intranet.gonicus.de;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-xkjk4lqd1ph9;rport From: "leger" ;tag=fon33qim5m To: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.5.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="snom3",realm="asterisk",nonce="16e4e5e0",uri="sip:111@dyn-195.intranet.gonicus.de;user=phone",response="7ffb3cf8c56762599c96781408e884af",algorithm=md5 Content-Type: application/sdp Content-Length: 473 v=0 o=root 1586199921 1586199921 IN IP4 10.3.67.172 s=call c=IN IP4 10.3.67.172 t=0 0 m=audio 65464 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:qec5lVtP1Yzrpd4owTxcNmHIHFZ/xcuK02uHpOV6 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: INVITE sip:111@dyn-195.intranet.gonicus.de;user=phone SIP/2.0 (61) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-xkjk4lqd1ph9;rport (67) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "leger" ;tag=fon33qim5m (68) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: (52) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 (55) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 2 INVITE (14) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Contact: ;flow-id=1 (61) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: User-Agent: snom360/6.5.2 (25) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: Accept: application/sdp (23) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 15: Min-SE: 90 (10) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 16: Proxy-Authorization: Digest username="snom3",realm="asterisk",nonce="16e4e5e0",uri="sip:111@dyn-195.intranet.gonicus.de;user=phone",response="7ffb3cf8c56762599c96781408e884af",algorithm=md5 (189) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 17: Content-Type: application/sdp (29) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 18: Content-Length: 473 (19) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 19: (0) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: v=0 (3) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: o=root 1586199921 1586199921 IN IP4 10.3.67.172 (47) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: s=call (6) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: c=IN IP4 10.3.67.172 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: t=0 0 (5) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: m=audio 65464 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:qec5lVtP1Yzrpd4owTxcNmHIHFZ/xcuK02uHpOV6 (82) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=ptime:20 (10) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=encryption:optional (21) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=sendrecv (10) [Dec 4 14:20:41] --- (19 headers 19 lines) --- [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:11268 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 4 14:20:41] Using INVITE request as basis request - 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 [Dec 4 14:20:41] Sending to 10.3.67.172 : 2051 (NAT) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:7265 check_user_full: Setting NAT on RTP to 0 [Dec 4 14:20:41] Found user 'snom3' [Dec 4 14:20:41] Found RTP audio format 0 [Dec 4 14:20:41] Found RTP audio format 8 [Dec 4 14:20:41] Found RTP audio format 9 [Dec 4 14:20:41] Found RTP audio format 2 [Dec 4 14:20:41] Found RTP audio format 3 [Dec 4 14:20:41] Found RTP audio format 18 [Dec 4 14:20:41] Found RTP audio format 4 [Dec 4 14:20:41] Found RTP audio format 101 [Dec 4 14:20:41] Peer audio RTP is at port 10.3.67.172:65464 [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:3668 process_sdp: Peer audio RTP is at port 10.3.67.172:65464 [Dec 4 14:20:41] Found description format pcmu [Dec 4 14:20:41] Found description format pcma [Dec 4 14:20:41] Found description format g722 [Dec 4 14:20:41] Found description format g726-32 [Dec 4 14:20:41] Found description format gsm [Dec 4 14:20:41] Found description format g729 [Dec 4 14:20:41] Found description format g723 [Dec 4 14:20:41] Found description format telephone-event [Dec 4 14:20:41] Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Dec 4 14:20:41] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:10632 handle_request_invite: Checking SIP call limits for device snom3 [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:2220 update_call_counter: Updating call counter for incoming call [Dec 4 14:20:41] Looking for 111 in default (domain dyn-195.intranet.gonicus.de;user=phone) [Dec 4 14:20:41] DEBUG[13005]: chan_sip.c:6241 build_route: build_route: Contact hop: ;flow-id=1 [Dec 4 14:20:41] list_route: hop: [Dec 4 14:20:41] Transmitting (no NAT) to 10.3.67.172:2051: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-xkjk4lqd1ph9;received=10.3.67.172;rport=2051 From: "leger" ;tag=fon33qim5m To: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Dec 4 14:20:41] DEBUG[12999]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom3 [Dec 4 14:20:41] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for SIP/snom3 - state 2 (In use) [Dec 4 14:20:41] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Goto' [Dec 4 14:20:41] -- Executing Goto("SIP/snom3-081ae3f8", "edv|s|1") in new stack [Dec 4 14:20:41] -- Goto (edv,s,1) [Dec 4 14:20:41] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Set' [Dec 4 14:20:41] -- Executing Set("SIP/snom3-081ae3f8", "LANGUAGE()=de") in new stack [Dec 4 14:20:41] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Ringing' [Dec 4 14:20:41] -- Executing Ringing("SIP/snom3-081ae3f8", "") in new stack [Dec 4 14:20:41] Transmitting (no NAT) to 10.3.67.172:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-xkjk4lqd1ph9;received=10.3.67.172;rport=2051 From: "leger" ;tag=fon33qim5m To: ;tag=as2dc67d6a Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- [Dec 4 14:20:41] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Wait' [Dec 4 14:20:41] -- Executing Wait("SIP/snom3-081ae3f8", "1") in new stack [Dec 4 14:20:41] DEBUG[13010]: app_queue.c:500 changethread: Device 'SIP/snom3' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:42] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Answer' [Dec 4 14:20:42] -- Executing Answer("SIP/snom3-081ae3f8", "") in new stack [Dec 4 14:20:42] DEBUG[13009]: chan_sip.c:2560 sip_answer: sip_answer(SIP/snom3-081ae3f8) [Dec 4 14:20:42] We're at 10.3.67.195 port 11536 [Dec 4 14:20:42] Adding codec 0x4 (ulaw) to SDP [Dec 4 14:20:42] Adding codec 0x8 (alaw) to SDP [Dec 4 14:20:42] Adding non-codec 0x1 (telephone-event) to SDP [Dec 4 14:20:42] Reliably Transmitting (no NAT) to 10.3.67.172:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-xkjk4lqd1ph9;received=10.3.67.172;rport=2051 From: "leger" ;tag=fon33qim5m To: ;tag=as2dc67d6a Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 238 v=0 o=root 12994 12994 IN IP4 10.3.67.195 s=session c=IN IP4 10.3.67.195 t=0 0 m=audio 11536 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Dec 4 14:20:42] DEBUG[13009]: chan_sip.c:1306 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #9 [Dec 4 14:20:42] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Playback' [Dec 4 14:20:42] -- Executing Playback("SIP/snom3-081ae3f8", "edv") in new stack [Dec 4 14:20:42] WARNING[13009]: file.c:512 ast_openstream_full: File edv does not exist in any format [Dec 4 14:20:42] WARNING[13009]: file.c:824 ast_streamfile: Unable to open edv (format ulaw): No such file or directory [Dec 4 14:20:42] WARNING[13009]: app_playback.c:133 playback_exec: ast_streamfile failed on SIP/snom3-081ae3f8 for edv [Dec 4 14:20:42] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'SetCIDName' [Dec 4 14:20:42] -- Executing SetCIDName("SIP/snom3-081ae3f8", "Ueber Hotline") in new stack [Dec 4 14:20:42] WARNING[13009]: app_setcidname.c:71 setcallerid_exec: SetCIDName is deprecated, please use Set(CALLERID(name)=value) instead. [Dec 4 14:20:42] DEBUG[13009]: pbx.c:1677 pbx_extension_helper: Launching 'Queue' [Dec 4 14:20:42] -- Executing Queue("SIP/snom3-081ae3f8", "edv|tT|300") in new stack [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:3068 queue_exec: NO QUEUE_PRIO variable found. Using default. [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:3076 queue_exec: queue: edv, options: tT, url: 300, announce: (null), expires: 0, priority: 0 [Dec 4 14:20:42] DEBUG[12999]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom3 [Dec 4 14:20:42] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for SIP/snom3 - state 2 (In use) [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:1170 join_queue: Queue 'edv' Join, Channel 'SIP/snom3-081ae3f8', Position '1' [Dec 4 14:20:42] DEBUG[13009]: channel.c:2408 set_format: Set channel SIP/snom3-081ae3f8 to write format slin [Dec 4 14:20:42] -- Started music on hold, class 'default', on channel 'SIP/snom3-081ae3f8' [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:2020 is_our_turn: It's our turn (SIP/snom3-081ae3f8). [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:2215 try_calling: SIP/snom3-081ae3f8 is trying to call a queue member. [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:2237 try_calling: Queue with URL=300_ [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:2237 try_calling: Queue with URL=300_ [Dec 4 14:20:42] DEBUG[13009]: app_queue.c:2237 try_calling: Queue with URL=300_ [Dec 4 14:20:43] DEBUG[13009]: app_queue.c:1640 ring_one: Trying 'Agent/130' with metric 0 [Dec 4 14:20:43] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/106@default - state 2 (In use) [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-7. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-6. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable PLAYBACKSTATUS. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-5. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-4. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-3. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-2. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-1. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-default-111-1. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Dec 4 14:20:43] DEBUG[13009]: channel.c:2902 ast_channel_inherit_variables: Not copying variable SIPURI. [Dec 4 14:20:43] -- outgoing agentcall, to agent '130', on 'Local/106@default-1720,1' [Dec 4 14:20:43] -- Called Agent/130 [Dec 4 14:20:43] DEBUG[13011]: app_queue.c:500 changethread: Device 'SIP/snom3' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:43] DEBUG[13012]: app_queue.c:500 changethread: Device 'Local/106@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:43] DEBUG[13013]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' [Dec 4 14:20:43] -- Executing Dial("Local/106@default-1720,2", "SIP/snom2||tT") in new stack [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:1888 create_addr_from_peer: Setting NAT on RTP to 0 [Dec 4 14:20:43] DEBUG[13013]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-default-106-1. [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:2082 sip_call: Outgoing Call for snom2 [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:2220 update_call_counter: [Dec 4 14:20:43] <-- SIP read from 10.3.67.172:2051: ACK sip:111@10.3.67.195 SIP/2.0 Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-o3nuch682tzj;rport From: "leger" ;tag=fon33qim5m To: ;tag=as2dc67d6a Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Updating call counter for outgoing call [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: ACK sip:111@10.3.67.195 SIP/2.0 (31) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.172:2051;branch=z9hG4bK-o3nuch682tzj;rport (67) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "leger" ;tag=fon33qim5m (68) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=as2dc67d6a (67) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69 (55) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 2 ACK (11) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Contact: ;flow-id=1 (61) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Content-Length: 0 (17) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: (0) [Dec 4 14:20:43] --- (9 headers 0 lines) --- [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:11268 handle_request: **** Received ACK (6) - Command in SIP ACK [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:1402 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #9 [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:1414 __sip_ack: Stopping retransmission on '3c38fcfc927c-jdgnhbduwlaj@snom360-000413231E69' of Response 2: Match Found [Dec 4 14:20:43] We're at 10.3.67.195 port 12040 [Dec 4 14:20:43] Adding codec 0x4 (ulaw) to SDP [Dec 4 14:20:43] Adding codec 0x8 (alaw) to SDP [Dec 4 14:20:43] Adding non-codec 0x1 (telephone-event) to SDP [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 0: INVITE sip:snom2@10.3.67.121:2054;line=viztnhon SIP/2.0 (55) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK7b666d9a;rport (62) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as7ff000be (60) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 3: To: (46) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 4: Contact: (32) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 5: Call-ID: 1d1eb5230fa5c74f521058537600356e@10.3.67.195 (53) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 4 14:20:43] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 9: Date: Mon, 04 Dec 2006 13:20:43 GMT (35) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 11: Content-Type: application/sdp (29) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 12: Content-Length: 238 (19) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3427 parse_request: Header 13: (0) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: v=0 (3) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: o=root 12994 12994 IN IP4 10.3.67.195 (37) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: s=session (9) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: c=IN IP4 10.3.67.195 (20) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: t=0 0 (5) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: m=audio 12040 RTP/AVP 0 8 101 (29) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:3459 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 4 14:20:43] 13 headers, 11 lines [Dec 4 14:20:43] Reliably Transmitting (no NAT) to 10.3.67.121:2054: INVITE sip:snom2@10.3.67.121:2054;line=viztnhon SIP/2.0 Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK7b666d9a;rport From: "Ueber Hotline" ;tag=as7ff000be To: Contact: Call-ID: 1d1eb5230fa5c74f521058537600356e@10.3.67.195 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 04 Dec 2006 13:20:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 238 v=0 o=root 12994 12994 IN IP4 10.3.67.195 s=session c=IN IP4 10.3.67.195 t=0 0 m=audio 12040 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:1306 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #10 [Dec 4 14:20:43] -- Called snom2 [Dec 4 14:20:43] <-- SIP read from 10.3.67.121:2054: SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK7b666d9a;rport=5060 From: "Ueber Hotline" ;tag=as7ff000be To: ;tag=l70tb8jdj3 Call-ID: 1d1eb5230fa5c74f521058537600356e@10.3.67.195 CSeq: 102 INVITE Contact: Diversion: ;reason="user-busy" Content-Length: 0 [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: SIP/2.0 302 Moved Temporarily (29) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK7b666d9a;rport=5060 (67) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as7ff000be (60) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=l70tb8jdj3 (61) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 1d1eb5230fa5c74f521058537600356e@10.3.67.195 (53) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Contact: (46) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Diversion: ;reason="user-busy" (72) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Content-Length: 0 (17) [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: (0) [Dec 4 14:20:43] --- (9 headers 0 lines) --- [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:1391 __sip_ack: Acked pending invite 102 [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:1402 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #10 [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:1414 __sip_ack: Stopping retransmission on '1d1eb5230fa5c74f521058537600356e@10.3.67.195' of Request 102: Match Found [Dec 4 14:20:43] -- Got SIP response 302 "Moved Temporarily" back from 10.3.67.121 [Dec 4 14:20:43] DEBUG[13005]: chan_sip.c:9657 parse_moved_contact: Found 302 Redirect to extension '111' [Dec 4 14:20:43] Transmitting (no NAT) to 10.3.67.121:2054: ACK sip:snom2@10.3.67.121:2054;line=viztnhon SIP/2.0 Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK7b666d9a;rport From: "Ueber Hotline" ;tag=as7ff000be To: ;tag=l70tb8jdj3 Contact: Call-ID: 1d1eb5230fa5c74f521058537600356e@10.3.67.195 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 4 14:20:43] -- Now forwarding Local/106@default-1720,2 to 'Local/111@default' (thanks to SIP/snom2-081b81f0) [Dec 4 14:20:43] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/111@default - state 2 (In use) [Dec 4 14:20:43] DEBUG[13014]: app_queue.c:500 changethread: Device 'Local/111@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:43] DEBUG[13013]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-default-106-1. [Dec 4 14:20:43] DEBUG[13013]: channel.c:1367 ast_hangup: Hanging up channel 'SIP/snom2-081b81f0' [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:2430 sip_hangup: Hangup call SIP/snom2-081b81f0, SIP callid 1d1eb5230fa5c74f521058537600356e@10.3.67.195) [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:2438 sip_hangup: update_call_counter(snom2) - decrement call limit counter [Dec 4 14:20:43] DEBUG[13013]: chan_sip.c:2220 update_call_counter: Updating call counter for outgoing call [Dec 4 14:20:43] DEBUG[12999]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom2 [Dec 4 14:20:43] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for SIP/snom2 - state 1 (Not in use) [Dec 4 14:20:43] DEBUG[13016]: app_queue.c:500 changethread: Device 'SIP/snom2' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 4 14:20:43] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Goto' [Dec 4 14:20:43] -- Executing Goto("Local/111@default-7133,2", "edv|s|1") in new stack [Dec 4 14:20:43] -- Goto (edv,s,1) [Dec 4 14:20:43] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Set' [Dec 4 14:20:43] -- Executing Set("Local/111@default-7133,2", "LANGUAGE()=de") in new stack [Dec 4 14:20:43] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Ringing' [Dec 4 14:20:43] -- Executing Ringing("Local/111@default-7133,2", "") in new stack [Dec 4 14:20:43] -- Local/111@default-7133,1 is ringing [Dec 4 14:20:43] -- Agent/130 is ringing [Dec 4 14:20:43] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Wait' [Dec 4 14:20:43] -- Executing Wait("Local/111@default-7133,2", "1") in new stack [Dec 4 14:20:43] DEBUG[13009]: channel.c:2030 ast_read: Auto-deactivating generator [Dec 4 14:20:43] DEBUG[13009]: channel.c:2408 set_format: Set channel SIP/snom3-081ae3f8 to write format ulaw [Dec 4 14:20:43] -- Stopped music on hold on SIP/snom3-081ae3f8 [Dec 4 14:20:44] Destroying call '1d1eb5230fa5c74f521058537600356e@10.3.67.195' [Dec 4 14:20:44] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Answer' [Dec 4 14:20:44] -- Executing Answer("Local/111@default-7133,2", "") in new stack [Dec 4 14:20:44] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Playback' [Dec 4 14:20:44] -- Executing Playback("Local/111@default-7133,2", "edv") in new stack [Dec 4 14:20:44] WARNING[13015]: file.c:512 ast_openstream_full: File edv does not exist in any format [Dec 4 14:20:44] WARNING[13015]: file.c:824 ast_streamfile: Unable to open edv (format ulaw): No such file or directory [Dec 4 14:20:44] WARNING[13015]: app_playback.c:133 playback_exec: ast_streamfile failed on Local/111@default-7133,2 for edv [Dec 4 14:20:44] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'SetCIDName' [Dec 4 14:20:44] -- Executing SetCIDName("Local/111@default-7133,2", "Ueber Hotline") in new stack [Dec 4 14:20:44] DEBUG[13015]: pbx.c:1677 pbx_extension_helper: Launching 'Queue' [Dec 4 14:20:44] -- Executing Queue("Local/111@default-7133,2", "edv|tT|300") in new stack [Dec 4 14:20:44] DEBUG[13015]: app_queue.c:3068 queue_exec: NO QUEUE_PRIO variable found. Using default. [Dec 4 14:20:44] DEBUG[13015]: app_queue.c:3076 queue_exec: queue: edv, options: tT, url: 300, announce: (null), expires: 0, priority: 0 [Dec 4 14:20:44] DEBUG[13015]: app_queue.c:1170 join_queue: Queue 'edv' Join, Channel 'Local/111@default-7133,2', Position '2' [Dec 4 14:20:44] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format slin [Dec 4 14:20:44] -- Started music on hold, class 'default', on channel 'Local/111@default-7133,2' [Dec 4 14:20:44] DEBUG[13015]: app_queue.c:2024 is_our_turn: It's not our turn (Local/111@default-7133,2). [Dec 4 14:20:44] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format ulaw [Dec 4 14:20:44] -- Stopped music on hold on Local/111@default-7133,2 [Dec 4 14:20:44] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format gsm [Dec 4 14:20:44] -- Local/111@default-7133,1 answered Local/106@default-1720,2 [Dec 4 14:20:44] DEBUG[13009]: app_queue.c:1953 wait_for_answer: Dunno what to do with control type -1 [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/111@default - state 2 (In use) [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/111@default - state 2 (In use) [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/106@default - state 2 (In use) [Dec 4 14:20:44] -- Playing 'queue-thereare' (language 'de') [Dec 4 14:20:44] -- Agent/130 answered SIP/snom3-081ae3f8 [Dec 4 14:20:44] DEBUG[13009]: app_queue.c:1673 store_next: Next is 'Agent/129' with metric 1 [Dec 4 14:20:44] DEBUG[13009]: app_queue.c:2401 try_calling: app_queue: sendurl=300. [Dec 4 14:20:44] DEBUG[13013]: channel.c:2834 ast_channel_masquerade: Planning to masquerade channel Local/111@default-7133,1 into the structure of Local/106@default-1720,1 [Dec 4 14:20:44] DEBUG[13013]: channel.c:2847 ast_channel_masquerade: Done planning to masquerade channel Local/111@default-7133,1 into the structure of Local/106@default-1720,1 [Dec 4 14:20:44] DEBUG[13013]: chan_local.c:262 local_write: Not posting to queue since already masked on 'Local/106@default-1720,2' [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/106@default - state 2 (In use) [Dec 4 14:20:44] DEBUG[13009]: channel.c:2961 ast_do_masquerade: Actually Masquerading Local/111@default-7133,1(6) into the structure of Local/106@default-1720,1(6) [Dec 4 14:20:44] DEBUG[13009]: channel.c:2972 ast_do_masquerade: Got clone lock for masquerade on 'Local/111@default-7133,1' at 0x81be45c [Dec 4 14:20:44] DEBUG[13009]: channel.c:3154 ast_do_masquerade: Putting channel Local/111@default-7133,1 in 4/4 formats [Dec 4 14:20:44] DEBUG[13009]: channel.c:3189 ast_do_masquerade: Released clone lock on 'Local/106@default-1720,1' [Dec 4 14:20:44] DEBUG[13009]: channel.c:3198 ast_do_masquerade: Done Masquerading Local/111@default-7133,1 (6) [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Agent/130 - state 3 (Busy) [Dec 4 14:20:44] DEBUG[13013]: channel.c:3380 ast_generic_bridge: Didn't get a frame from channel: Local/106@default-1720,2 [Dec 4 14:20:44] DEBUG[13013]: channel.c:3669 ast_channel_bridge: Bridge stops bridging channels Local/106@default-1720,2 and Local/106@default-1720,1 [Dec 4 14:20:44] DEBUG[13013]: channel.c:1372 ast_hangup: Hanging up zombie 'Local/106@default-1720,1' [Dec 4 14:20:44] DEBUG[13013]: app_dial.c:1636 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 4 14:20:44] DEBUG[13013]: pbx.c:2316 __ast_pbx_run: Spawn extension (default,106,1) exited non-zero on 'Local/106@default-1720,2' [Dec 4 14:20:44] == Spawn extension (default, 106, 1) exited non-zero on 'Local/106@default-1720,2' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"Ueber Hotline" ' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'snom3' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '106' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'default' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Local/106@default-1720,2' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Local/111@default-7133,1' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/snom2||tT' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:43' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:44' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:44' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1165238443.2' [Dec 4 14:20:44] DEBUG[13013]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' [Dec 4 14:20:44] DEBUG[13013]: channel.c:1367 ast_hangup: Hanging up channel 'Local/106@default-1720,2' [Dec 4 14:20:44] DEBUG[13009]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 4 14:20:44] DEBUG[13017]: app_queue.c:500 changethread: Device 'Local/111@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:44] DEBUG[13018]: app_queue.c:500 changethread: Device 'Local/111@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:44] DEBUG[13019]: app_queue.c:500 changethread: Device 'Local/106@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:44] DEBUG[13020]: app_queue.c:500 changethread: Device 'Local/106@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:44] DEBUG[13021]: app_queue.c:506 changethread: Device 'Agent/130' changed to state '3' (Busy) [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/106@default - state 0 (Unknown) [Dec 4 14:20:44] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/106@default - state 0 (Unknown) [Dec 4 14:20:44] DEBUG[13022]: app_queue.c:500 changethread: Device 'Local/106@default' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 14:20:44] DEBUG[13023]: app_queue.c:500 changethread: Device 'Local/106@default' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 14:20:44] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:45] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:46] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format ulaw [Dec 4 14:20:46] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format gsm [Dec 4 14:20:46] -- Playing 'digits/1' (language 'de') [Dec 4 14:20:46] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format ulaw [Dec 4 14:20:46] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format gsm [Dec 4 14:20:46] -- Playing 'queue-callswaiting' (language 'de') [Dec 4 14:20:46] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:48] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:48] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format ulaw [Dec 4 14:20:48] -- Hold time for edv is 0 minutes 0 seconds [Dec 4 14:20:48] -- Told Local/111@default-7133,2 in edv their queue position (which was 1) [Dec 4 14:20:48] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format gsm [Dec 4 14:20:48] -- Playing 'queue-thankyou' (language 'de') [Dec 4 14:20:49] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:50] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:50] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format ulaw [Dec 4 14:20:50] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format slin [Dec 4 14:20:50] -- Started music on hold, class 'default', on channel 'Local/111@default-7133,2' [Dec 4 14:20:50] DEBUG[13015]: channel.c:2030 ast_read: Auto-deactivating generator [Dec 4 14:20:50] DEBUG[13015]: channel.c:2408 set_format: Set channel Local/111@default-7133,2 to write format ulaw [Dec 4 14:20:50] -- Stopped music on hold on Local/111@default-7133,2 [Dec 4 14:20:51] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:51] DEBUG[13015]: app_queue.c:2020 is_our_turn: It's our turn (Local/111@default-7133,2). [Dec 4 14:20:51] DEBUG[13015]: app_queue.c:2215 try_calling: Local/111@default-7133,2 is trying to call a queue member. [Dec 4 14:20:51] DEBUG[13015]: app_queue.c:2237 try_calling: Queue with URL=300_ [Dec 4 14:20:51] DEBUG[13015]: app_queue.c:2237 try_calling: Queue with URL=300_ [Dec 4 14:20:51] DEBUG[13015]: app_queue.c:2237 try_calling: Queue with URL=300_ [Dec 4 14:20:51] DEBUG[13015]: app_queue.c:1640 ring_one: Trying 'Agent/129' with metric 1 [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-7. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-6. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable PLAYBACKSTATUS. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-5. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-4. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-3. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-2. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-edv-s-1. [Dec 4 14:20:51] DEBUG[13015]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-default-111-1. [Dec 4 14:20:51] -- outgoing agentcall, to agent '129', on 'Local/105@default-33e2,1' [Dec 4 14:20:51] -- Called Agent/129 [Dec 4 14:20:51] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/105@default - state 2 (In use) [Dec 4 14:20:51] DEBUG[13024]: pbx.c:1677 pbx_extension_helper: Launching 'Dial' [Dec 4 14:20:51] -- Executing Dial("Local/105@default-33e2,2", "SIP/snom1||tT") in new stack [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3176 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:1888 create_addr_from_peer: Setting NAT on RTP to 0 [Dec 4 14:20:51] DEBUG[13024]: channel.c:2902 ast_channel_inherit_variables: Not copying variable STACK-default-105-1. [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:2082 sip_call: Outgoing Call for snom1 [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:2220 update_call_counter: Updating call counter for outgoing call [Dec 4 14:20:51] We're at 10.3.67.195 port 18646 [Dec 4 14:20:51] Adding codec 0x4 (ulaw) to SDP [Dec 4 14:20:51] Adding codec 0x8 (alaw) to SDP [Dec 4 14:20:51] Adding non-codec 0x1 (telephone-event) to SDP [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 0: INVITE sip:snom1@10.3.67.149:2051;line=bvnn8r97 SIP/2.0 (55) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport (62) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as558bd2b6 (60) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 3: To: (46) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 4: Contact: (32) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 5: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 6: CSeq: 102 INVITE (16) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 7: User-Agent: Asterisk PBX (24) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 8: Max-Forwards: 70 (16) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 9: Date: Mon, 04 Dec 2006 13:20:51 GMT (35) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 11: Content-Type: application/sdp (29) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 12: Content-Length: 238 (19) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3427 parse_request: Header 13: (0) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: v=0 (3) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: o=root 12994 12994 IN IP4 10.3.67.195 (37) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: s=session (9) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: c=IN IP4 10.3.67.195 (20) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: t=0 0 (5) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: m=audio 18646 RTP/AVP 0 8 101 (29) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:3459 parse_request: Line: a=silenceSupp:off - - - - (25) [Dec 4 14:20:51] 13 headers, 11 lines [Dec 4 14:20:51] Reliably Transmitting (no NAT) to 10.3.67.149:2051: INVITE sip:snom1@10.3.67.149:2051;line=bvnn8r97 SIP/2.0 Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport From: "Ueber Hotline" ;tag=as558bd2b6 To: Contact: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 04 Dec 2006 13:20:51 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 238 v=0 o=root 12994 12994 IN IP4 10.3.67.195 s=session c=IN IP4 10.3.67.195 t=0 0 m=audio 18646 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- [Dec 4 14:20:51] DEBUG[13024]: chan_sip.c:1306 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #11 [Dec 4 14:20:51] -- Called snom1 [Dec 4 14:20:51] DEBUG[13025]: app_queue.c:500 changethread: Device 'Local/105@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:51] <-- SIP read from 10.3.67.149:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 From: "Ueber Hotline" ;tag=as558bd2b6 To: ;tag=23ysp499ub Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 (67) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as558bd2b6 (60) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=23ysp499ub (61) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Contact: ;flow-id=1 (61) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: Content-Length: 0 (17) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: (0) [Dec 4 14:20:51] --- (10 headers 0 lines) --- [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:1458 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #11 - INVITE (got response) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195' Request 102: Found [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:9694 handle_response_invite: SIP response 180 to standard invite [Dec 4 14:20:51] -- SIP/snom1-081b81f0 is ringing [Dec 4 14:20:51] -- Agent/129 is ringing [Dec 4 14:20:51] DEBUG[12999]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom1 [Dec 4 14:20:51] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for SIP/snom1 - state 6 (Ringing) [Dec 4 14:20:51] DEBUG[13026]: app_queue.c:506 changethread: Device 'SIP/snom1' changed to state '6' (Ringing) [Dec 4 14:20:51] <-- SIP read from 10.3.67.149:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 From: "Ueber Hotline" ;tag=as558bd2b6 To: ;tag=23ysp499ub Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 (67) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as558bd2b6 (60) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=23ysp499ub (61) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Contact: ;flow-id=1 (61) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: Content-Length: 0 (17) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: (0) [Dec 4 14:20:51] --- (10 headers 0 lines) --- [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195' Request 102: Found [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:9694 handle_response_invite: SIP response 180 to standard invite [Dec 4 14:20:51] -- SIP/snom1-081b81f0 is ringing [Dec 4 14:20:51] <-- SIP read from 10.3.67.149:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 From: "Ueber Hotline" ;tag=as558bd2b6 To: ;tag=23ysp499ub Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 (67) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as558bd2b6 (60) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=23ysp499ub (61) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Contact: ;flow-id=1 (61) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: Content-Length: 0 (17) [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: (0) [Dec 4 14:20:51] --- (10 headers 0 lines) --- [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195' Request 102: Found [Dec 4 14:20:51] DEBUG[13005]: chan_sip.c:9694 handle_response_invite: SIP response 180 to standard invite [Dec 4 14:20:51] -- SIP/snom1-081b81f0 is ringing [Dec 4 14:20:52] DEBUG[13009]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:52] <-- SIP read from 10.3.67.149:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 From: "Ueber Hotline" ;tag=as558bd2b6 To: ;tag=23ysp499ub Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Content-Length: 0 [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: SIP/2.0 180 Ringing (19) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 (67) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as558bd2b6 (60) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=23ysp499ub (61) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Contact: ;flow-id=1 (61) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: Content-Length: 0 (17) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: (0) [Dec 4 14:20:52] --- (10 headers 0 lines) --- [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:1467 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195' Request 102: Found [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:9694 handle_response_invite: SIP response 180 to standard invite [Dec 4 14:20:52] -- SIP/snom1-081b81f0 is ringing [Dec 4 14:20:52] DEBUG[13024]: rtp.c:411 ast_rtcp_read: Got RTCP report of 52 bytes [Dec 4 14:20:52] <-- SIP read from 10.3.67.149:2051: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 From: "Ueber Hotline" ;tag=as558bd2b6 To: ;tag=23ysp499ub Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom360/6.2.2 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Content-Type: application/sdp Content-Length: 313 v=0 o=root 1030926867 1030926868 IN IP4 10.3.67.149 s=call c=IN IP4 10.3.67.149 t=0 0 m=audio 51318 RTP/AVP 0 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:frmLtU65ezXoFFlxWcx3LVXt+Zrkpn2sWvE2L/W2 a=rtpmap:0 pcmu/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=encryption:optional a=sendrecv [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: SIP/2.0 200 Ok (14) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK05db763a;rport=5060 (67) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: "Ueber Hotline" ;tag=as558bd2b6 (60) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: ;tag=23ysp499ub (61) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 102 INVITE (16) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Contact: ;flow-id=1 (61) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: User-Agent: snom360/6.2.2 (25) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: Supported: timer, 100rel, replaces, callerid (44) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 11: Content-Type: application/sdp (29) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 12: Content-Length: 313 (19) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 13: (0) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: v=0 (3) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: o=root 1030926867 1030926868 IN IP4 10.3.67.149 (47) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: s=call (6) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: c=IN IP4 10.3.67.149 (20) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: t=0 0 (5) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: m=audio 51318 RTP/AVP 0 101 (27) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:frmLtU65ezXoFFlxWcx3LVXt+Zrkpn2sWvE2L/W2 (82) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=encryption:optional (21) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=sendrecv (10) [Dec 4 14:20:52] --- (13 headers 12 lines) --- [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:1391 __sip_ack: Acked pending invite 102 [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:1414 __sip_ack: Stopping retransmission on '10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195' of Request 102: Match Found [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:9694 handle_response_invite: SIP response 200 to standard invite [Dec 4 14:20:52] Found RTP audio format 0 [Dec 4 14:20:52] Found RTP audio format 101 [Dec 4 14:20:52] Peer audio RTP is at port 10.3.67.149:51318 [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:3668 process_sdp: Peer audio RTP is at port 10.3.67.149:51318 [Dec 4 14:20:52] Found description format pcmu [Dec 4 14:20:52] Found description format telephone-event [Dec 4 14:20:52] Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x4 (ulaw)/video=0x0 (nothing), combined - 0x4 (ulaw) [Dec 4 14:20:52] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Dec 4 14:20:52] DEBUG[13005]: chan_sip.c:6241 build_route: build_route: Contact hop: ;flow-id=1 [Dec 4 14:20:52] list_route: hop: [Dec 4 14:20:52] set_destination: Parsing for address/port to send to [Dec 4 14:20:52] set_destination: set destination to 10.3.67.149, port 2051 [Dec 4 14:20:52] Transmitting (no NAT) to 10.3.67.149:2051: ACK sip:snom1@10.3.67.149:2051;line=bvnn8r97 SIP/2.0 Via: SIP/2.0/UDP 10.3.67.195:5060;branch=z9hG4bK7f86ffc7;rport From: "Ueber Hotline" ;tag=as558bd2b6 To: ;tag=23ysp499ub Contact: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Dec 4 14:20:52] -- SIP/snom1-081b81f0 answered Local/105@default-33e2,2 [Dec 4 14:20:52] DEBUG[13015]: app_queue.c:1953 wait_for_answer: Dunno what to do with control type -1 [Dec 4 14:20:52] -- Agent/129 answered Local/111@default-7133,2 [Dec 4 14:20:52] DEBUG[13015]: app_queue.c:1673 store_next: Next is 'Agent/124' with metric 2 [Dec 4 14:20:52] DEBUG[13015]: app_queue.c:2401 try_calling: app_queue: sendurl=300. [Dec 4 14:20:52] DEBUG[12999]: chan_sip.c:11810 sip_devicestate: Checking device state for peer snom1 [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for SIP/snom1 - state 2 (In use) [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/105@default - state 2 (In use) [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/105@default - state 2 (In use) [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Agent/129 - state 3 (Busy) [Dec 4 14:20:52] DEBUG[13027]: app_queue.c:506 changethread: Device 'SIP/snom1' changed to state '2' (In use) [Dec 4 14:20:52] DEBUG[13028]: app_queue.c:500 changethread: Device 'Local/105@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:52] DEBUG[13029]: app_queue.c:500 changethread: Device 'Local/105@default' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Dec 4 14:20:52] DEBUG[13030]: app_queue.c:506 changethread: Device 'Agent/129' changed to state '3' (Busy) [Dec 4 14:20:52] DEBUG[13024]: rtp.c:1361 ast_rtp_write: Ooh, format changed from unknown to ulaw [Dec 4 14:20:52] DEBUG[13024]: channel.c:2834 ast_channel_masquerade: Planning to masquerade channel SIP/snom1-081b81f0 into the structure of Local/105@default-33e2,1 [Dec 4 14:20:52] DEBUG[13024]: channel.c:2847 ast_channel_masquerade: Done planning to masquerade channel SIP/snom1-081b81f0 into the structure of Local/105@default-33e2,1 [Dec 4 14:20:52] DEBUG[13024]: chan_local.c:262 local_write: Not posting to queue since already masked on 'Local/105@default-33e2,2' [Dec 4 14:20:52] DEBUG[13015]: channel.c:2961 ast_do_masquerade: Actually Masquerading SIP/snom1-081b81f0(6) into the structure of Local/105@default-33e2,1(6) [Dec 4 14:20:52] DEBUG[13015]: channel.c:2972 ast_do_masquerade: Got clone lock for masquerade on 'SIP/snom1-081b81f0' at 0x81b5e24 [Dec 4 14:20:52] DEBUG[13015]: channel.c:3154 ast_do_masquerade: Putting channel SIP/snom1-081b81f0 in 4/4 formats [Dec 4 14:20:52] DEBUG[13015]: channel.c:3189 ast_do_masquerade: Released clone lock on 'Local/105@default-33e2,1' [Dec 4 14:20:52] DEBUG[13015]: channel.c:3198 ast_do_masquerade: Done Masquerading SIP/snom1-081b81f0 (6) [Dec 4 14:20:52] DEBUG[13015]: chan_agent.c:547 agent_read: Bridge on 'SIP/snom1-081b81f0' being set to 'Agent/129' (3) [Dec 4 14:20:52] DEBUG[13024]: channel.c:3380 ast_generic_bridge: Didn't get a frame from channel: Local/105@default-33e2,2 [Dec 4 14:20:52] DEBUG[13024]: channel.c:3669 ast_channel_bridge: Bridge stops bridging channels Local/105@default-33e2,2 and Local/105@default-33e2,1 [Dec 4 14:20:52] DEBUG[13024]: channel.c:1372 ast_hangup: Hanging up zombie 'Local/105@default-33e2,1' [Dec 4 14:20:52] DEBUG[13024]: app_dial.c:1636 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Dec 4 14:20:52] DEBUG[13024]: pbx.c:2316 __ast_pbx_run: Spawn extension (default,105,1) exited non-zero on 'Local/105@default-33e2,2' [Dec 4 14:20:52] == Spawn extension (default, 105, 1) exited non-zero on 'Local/105@default-33e2,2' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"Ueber Hotline" ' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'snom3' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '105' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'default' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Local/105@default-33e2,2' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/snom1-081b81f0' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Dial' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'SIP/snom1||tT' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:51' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:52' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:52' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '0' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1165238451.8' [Dec 4 14:20:52] DEBUG[13024]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' [Dec 4 14:20:52] DEBUG[13024]: channel.c:1367 ast_hangup: Hanging up channel 'Local/105@default-33e2,2' [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/105@default - state 0 (Unknown) [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/105@default - state 0 (Unknown) [Dec 4 14:20:52] DEBUG[13031]: app_queue.c:500 changethread: Device 'Local/105@default' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 14:20:52] DEBUG[13032]: app_queue.c:500 changethread: Device 'Local/105@default' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 14:20:52] DEBUG[13015]: channel.c:2834 ast_channel_masquerade: Planning to masquerade channel Agent/129 into the structure of Local/111@default-7133,1 [Dec 4 14:20:52] DEBUG[13015]: channel.c:2847 ast_channel_masquerade: Done planning to masquerade channel Agent/129 into the structure of Local/111@default-7133,1 [Dec 4 14:20:52] DEBUG[13015]: chan_local.c:262 local_write: Not posting to queue since already masked on 'Local/111@default-7133,2' [Dec 4 14:20:52] DEBUG[13009]: channel.c:2961 ast_do_masquerade: Actually Masquerading Agent/129(6) into the structure of Local/111@default-7133,1(6) [Dec 4 14:20:52] DEBUG[13009]: channel.c:2972 ast_do_masquerade: Got clone lock for masquerade on 'Agent/129' at 0x81b5624 [Dec 4 14:20:52] DEBUG[13009]: channel.c:3154 ast_do_masquerade: Putting channel Agent/129 in 4/4 formats [Dec 4 14:20:52] DEBUG[13009]: channel.c:3189 ast_do_masquerade: Released clone lock on 'Local/111@default-7133,1' [Dec 4 14:20:52] DEBUG[13009]: channel.c:3198 ast_do_masquerade: Done Masquerading Agent/129 (6) [Dec 4 14:20:52] DEBUG[13009]: chan_agent.c:547 agent_read: Bridge on 'Agent/129' being set to 'Agent/130' (3) [Dec 4 14:20:52] DEBUG[13015]: channel.c:3380 ast_generic_bridge: Didn't get a frame from channel: Local/111@default-7133,2 [Dec 4 14:20:52] DEBUG[13015]: channel.c:3669 ast_channel_bridge: Bridge stops bridging channels Local/111@default-7133,2 and Local/111@default-7133,1 [Dec 4 14:20:52] DEBUG[13015]: channel.c:1372 ast_hangup: Hanging up zombie 'Local/111@default-7133,1' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:2316 __ast_pbx_run: Spawn extension (edv,s,7) exited non-zero on 'Local/111@default-7133,2' [Dec 4 14:20:52] == Spawn extension (edv, s, 7) exited non-zero on 'Local/111@default-7133,2' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '"Ueber Hotline" ' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'snom3' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 's' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'edv' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Local/111@default-7133,2' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Agent/129' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'Queue' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'edv|tT|300' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:43' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:44' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '2006-12-04 14:20:52' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '9' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '8' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '1165238443.6' [Dec 4 14:20:52] DEBUG[13015]: pbx.c:1522 pbx_substitute_variables_helper_full: Function result is '(null)' [Dec 4 14:20:52] DEBUG[13015]: channel.c:1367 ast_hangup: Hanging up channel 'Local/111@default-7133,2' [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/111@default - state 0 (Unknown) [Dec 4 14:20:52] DEBUG[12999]: devicestate.c:187 do_state_change: Changing state for Local/111@default - state 0 (Unknown) [Dec 4 14:20:52] DEBUG[13033]: app_queue.c:500 changethread: Device 'Local/111@default' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 14:20:52] DEBUG[13034]: app_queue.c:500 changethread: Device 'Local/111@default' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [Dec 4 14:20:53] <-- SIP read from 10.3.67.149:2051: INVITE sip:snom3@10.3.67.195 SIP/2.0 Via: SIP/2.0/UDP 10.3.67.149:2051;branch=z9hG4bK-1bme8uy6vw1o;rport From: ;tag=23ysp499ub To: "Ueber Hotline" ;tag=as558bd2b6 Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: resolution="31x13", keys="4" User-Agent: snom360/6.2.2 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 469 v=0 o=root 1030926867 1030926869 IN IP4 10.3.67.149 s=call c=IN IP4 0.0.0.0 t=0 0 m=audio 51318 RTP/AVP 0 8 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:frmLtU65ezXoFFlxWcx3LVXt+Zrkpn2sWvE2L/W2 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendonly [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 0: INVITE sip:snom3@10.3.67.195 SIP/2.0 (36) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 1: Via: SIP/2.0/UDP 10.3.67.149:2051;branch=z9hG4bK-1bme8uy6vw1o;rport (67) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 2: From: ;tag=23ysp499ub (63) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 3: To: "Ueber Hotline" ;tag=as558bd2b6 (58) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 4: Call-ID: 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 (53) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 5: CSeq: 1 INVITE (14) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 6: Max-Forwards: 70 (16) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 7: Contact: ;flow-id=1 (61) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 8: P-Key-Flags: resolution="31x13", keys="4" (41) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 9: User-Agent: snom360/6.2.2 (25) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 10: Accept: application/sdp (23) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 12: Allow-Events: talk, hold, refer (31) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 13: Supported: timer, 100rel, replaces, callerid (44) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 14: Session-Expires: 3600;refresher=uas (35) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 15: Min-SE: 90 (10) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 16: Content-Type: application/sdp (29) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 17: Content-Length: 469 (19) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3427 parse_request: Header 18: (0) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: v=0 (3) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: o=root 1030926867 1030926869 IN IP4 10.3.67.149 (47) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: s=call (6) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: c=IN IP4 0.0.0.0 (16) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: t=0 0 (5) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: m=audio 51318 RTP/AVP 0 8 9 2 3 18 4 101 (40) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:frmLtU65ezXoFFlxWcx3LVXt+Zrkpn2sWvE2L/W2 (82) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:0 pcmu/8000 (20) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:8 pcma/8000 (20) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:9 g722/8000 (20) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:2 g726-32/8000 (23) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:3 gsm/8000 (19) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:18 g729/8000 (21) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:4 g723/8000 (20) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=fmtp:101 0-16 (15) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=ptime:20 (10) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=encryption:optional (21) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3459 parse_request: Line: a=sendonly (10) [Dec 4 14:20:53] --- (18 headers 19 lines) --- [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:11268 handle_request: **** Received INVITE (5) - Command in SIP INVITE [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1014 parse_sip_options: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -timer- [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1032 parse_sip_options: Matched SIP option: timer [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -100rel- [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1032 parse_sip_options: Matched SIP option: 100rel [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -replaces- [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1032 parse_sip_options: Matched SIP option: replaces [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1026 parse_sip_options: Found SIP option: -callerid- [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1037 parse_sip_options: Found no match for SIP option: callerid (Please file bug report!) [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:1043 parse_sip_options: * SIP extension value: 7 for call 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 [Dec 4 14:20:53] Using INVITE request as basis request - 10bae5733ecae3437cbaed9e3917e8ba@10.3.67.195 [Dec 4 14:20:53] Sending to 10.3.67.149 : 2051 (NAT) [Dec 4 14:20:53] Found RTP audio format 0 [Dec 4 14:20:53] Found RTP audio format 8 [Dec 4 14:20:53] Found RTP audio format 9 [Dec 4 14:20:53] Found RTP audio format 2 [Dec 4 14:20:53] Found RTP audio format 3 [Dec 4 14:20:53] Found RTP audio format 18 [Dec 4 14:20:53] Found RTP audio format 4 [Dec 4 14:20:53] Found RTP audio format 101 [Dec 4 14:20:53] Peer audio RTP is at port 0.0.0.0:51318 [Dec 4 14:20:53] DEBUG[13005]: chan_sip.c:3668 process_sdp: Peer audio RTP is at port 0.0.0.0:51318 [Dec 4 14:20:53] Found description format pcmu [Dec 4 14:20:53] Found description format pcma [Dec 4 14:20:53] Found description format g722 [Dec 4 14:20:53] Found description format g726-32 [Dec 4 14:20:53] Found description format gsm [Dec 4 14:20:53] Found description format g729 [Dec 4 14:20:53] Found description format g723 [Dec 4 14:20:53] Found description format telephone-event [Dec 4 14:20:53] Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) [Dec 4 14:20:53] Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)