[2009-03-20 10:16:38] VERBOSE[25812] logger.c: Asterisk Event Logger Started /var/log/asterisk/event_log [2009-03-20 10:16:38] VERBOSE[25812] logger.c: Asterisk Dynamic Loader Starting: [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/modules.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/modules.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/dnsmgr.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/dnsmgr.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/http.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/http.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Ping [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Events [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Logoff [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Login [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Challenge [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Hangup [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Status [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Setvar [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Getvar [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action GetConfig [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action GetConfigJSON [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action UpdateConfig [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action CreateConfig [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ListCategories [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Redirect [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Originate [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Command [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ExtensionState [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action AbsoluteTimeout [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action MailboxStatus [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action MailboxCount [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ListCommands [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action SendText [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action UserEvent [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action WaitEvent [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action CoreSettings [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action CoreStatus [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Reload [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action CoreShowChannels [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ModuleLoad [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ModuleCheck [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/manager.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/manager.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/users.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/users.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/cdr.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/cdr.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/rtp.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/rtp.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == RTP Allocating from port range 10000 -> 20000 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/udptl.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/udptl.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == UDPTL allocating from port range 4000 -> 4999 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: Asterisk PBX Core Initializing [2009-03-20 10:16:38] VERBOSE[25812] logger.c: Registering builtin applications: [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'EXCEPTION' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Answer] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Answer' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [BackGround] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'BackGround' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Busy] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Busy' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Congestion] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Congestion' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [ExecIfTime] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ExecIfTime' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Goto] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Goto' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [GotoIf] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'GotoIf' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [GotoIfTime] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'GotoIfTime' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [ImportVar] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ImportVar' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Hangup] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Hangup' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [NoOp] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'NoOp' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Proceeding] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Proceeding' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Progress] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Progress' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [RaiseException] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'RaiseException' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [ResetCDR] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ResetCDR' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Ringing] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Ringing' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [SayAlpha] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SayAlpha' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [SayDigits] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SayDigits' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [SayNumber] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SayNumber' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [SayPhonetic] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SayPhonetic' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Set] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Set' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [MSet] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'MSet' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [SetAMAFlags] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SetAMAFlags' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [Wait] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Wait' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: [WaitExten] [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'WaitExten' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ShowDialPlan [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Bridge' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ParkedCall' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Park' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ParkedCalls [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Park [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Bridge [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action DBGet [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action DBPut [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action DBDel [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action DBDelTree [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/enum.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/enum.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: Asterisk Dynamic Loader Starting: [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/modules.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/modules.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'answer' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'channel status' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'database del' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'database deltree' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'database get' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'database put' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'exec' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'get data' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'get full variable' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'get option' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'get variable' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'hangup' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'noop' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'receive char' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'receive text' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'record file' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say alpha' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say digits' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say number' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say phonetic' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say date' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say time' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'say datetime' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'send image' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'send text' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set autohangup' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set callerid' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set context' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set extension' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set music' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set priority' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'set variable' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'stream file' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'control stream file' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'tdd mode' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'verbose' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'wait for digit' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech create' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech set' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech destroy' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech load grammar' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech unload grammar' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech activate grammar' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech deactivate grammar' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == AGI Command 'speech recognize' registered [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'DeadAGI' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'EAGI' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action AGI [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'AGI' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: res_agi.so => (Asterisk Gateway Interface (AGI)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Monitor' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'StopMonitor' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ChangeMonitor' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'PauseMonitor' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'UnpauseMonitor' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action Monitor [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action StopMonitor [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action ChangeMonitor [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action PauseMonitor [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action UnpauseMonitor [2009-03-20 10:16:38] VERBOSE[25812] logger.c: res_monitor.so => (Call Monitoring Resource) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: res_ael_share.so => (share-able code for AEL) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Setting global variable 'CONSOLE' to '"Console/dsp"' [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Registered context 'reoriginate'(0x2aaaac00ae20) in local table 0x2aaaac00aa10; registrar: pbx_ael [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Registered extension context 'reoriginate' (0x2aaaac00ae20) in local table 0x2aaaac00aa10; registrar: pbx_ael [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 1 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 1 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 2 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 2 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 3 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 3 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 4 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 4 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 5 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 5 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 6 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 6 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 7 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 7 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 8 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 8 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 9 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 9 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension '_X.' priority 10 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension '_X.' priority 10 to reoriginate (0x2aaaac00ae20) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Time to scan old dialplan and merge leftovers back into the new: 0.000002 sec [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Time to restore hints and swap in new dialplan: 0.000001 sec [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Time to delete the old dialplan: 0.000000 sec [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Total time merge_contexts_delete: 0.000003 sec [2009-03-20 10:16:38] VERBOSE[25812] logger.c: pbx_ael.so => (Asterisk Extension Language Compiler) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'FIELDQTY' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'FILTER' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'REGEX' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'ARRAY' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'QUOTE' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'LEN' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'STRFTIME' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'STRPTIME' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'EVAL' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'KEYPADHASH' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'SPRINTF' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'HASHKEYS' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'HASH' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ClearHash' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'TOUPPER' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'TOLOWER' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: func_strings.so => (String handling dialplan functions) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'RAND' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: func_rand.so => (Random number dialplan function) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: pbx_spool.so => (Outgoing Spool Support) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'CALLERPRES' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'CALLERID' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: func_callerid.so => (Caller ID related dialplan functions) [2009-03-20 10:16:38] DEBUG[25812] channel.c: Registered handler for 'Local' (Local Proxy Channel Driver) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered channel type 'Local' (Local Proxy Channel Driver) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: chan_local.so => (Local Proxy Channel (Note: used internally by other modules)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: SIP channel loading... [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/sip.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/sip.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/users.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/users.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] DEBUG[25812] config.c: extract inaddr from [0.0.0.0] gives [0.0.0.0:5060](0) [2009-03-20 10:16:38] DEBUG[25812] chan_sip.c: Setting SIP channel User-Agent Name to VocalNet [2009-03-20 10:16:38] DEBUG[25812] acl.c: 0.0.0.0/255.255.255.255 sense 0 appended to acl for peer [2009-03-20 10:16:38] DEBUG[25812] acl.c: 0.0.0.0/255.255.255.255 sense 0 appended to acl for peer [2009-03-20 10:16:38] DEBUG[25812] acl.c: Trying to check A.ROOT-SERVERS.NET and get our IP address for that connection [2009-03-20 10:16:38] DEBUG[25812] acl.c: Found IP address for this socket [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == SIP Listening on 0.0.0.0:5060 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Using SIP CoS mark 4 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/sip_notify.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/sip_notify.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] DEBUG[25812] channel.c: Registered handler for 'SIP' (Session Initiation Protocol (SIP)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered channel type 'SIP' (Session Initiation Protocol (SIP)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SIPDtmfMode' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SIPAddHeader' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'SIP_HEADER' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'SIPPEER' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'SIPCHANINFO' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered custom function 'CHECKSIPDOMAIN' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action SIPpeers [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action SIPshowpeer [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Manager registered action SIPshowregistry [2009-03-20 10:16:38] VERBOSE[25812] logger.c: chan_sip.so => (Session Initiation Protocol (SIP)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/codecs.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/codecs.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- codec_ulaw: using generic PLC [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered translator 'ulawtolin' from format ulaw to slin, cost 1 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Resetting translation matrix [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered translator 'lintoulaw' from format slin to ulaw, cost 1 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Resetting translation matrix [2009-03-20 10:16:38] VERBOSE[25812] logger.c: codec_ulaw.so => (mu-Law Coder/Decoder) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/codecs.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/codecs.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- codec_dahdi: using generic PLC [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found transcoder 'DTE Encoder'. [2009-03-20 10:16:38] VERBOSE[25812] codec_dahdi.c: Opening transcoder channel from 2 to 8. [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered translator 'dahdiulawtog729' from format ulaw to g729, cost 1 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Resetting translation matrix [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from slin to g729, via ulaw [2009-03-20 10:16:38] VERBOSE[25812] codec_dahdi.c: Opening transcoder channel from 3 to 8. [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered translator 'dahdialawtog729' from format alaw to g729, cost 1 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Resetting translation matrix [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from slin to g729, via ulaw [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found transcoder 'DTE Decoder'. [2009-03-20 10:16:38] VERBOSE[25812] codec_dahdi.c: Opening transcoder channel from 8 to 2. [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered translator 'dahdig729toulaw' from format g729 to ulaw, cost 1 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Resetting translation matrix [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from alaw to ulaw, via g729 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from slin to g729, via ulaw [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from g729 to slin, via ulaw [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 3 cost path from alaw to slin, via ulaw [2009-03-20 10:16:38] VERBOSE[25812] codec_dahdi.c: Opening transcoder channel from 8 to 3. [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered translator 'dahdig729toalaw' from format g729 to alaw, cost 1 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Resetting translation matrix [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from ulaw to alaw, via g729 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from alaw to ulaw, via g729 [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 3 cost path from slin to alaw, via ulaw [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from slin to g729, via ulaw [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 2 cost path from g729 to slin, via ulaw [2009-03-20 10:16:38] DEBUG[25812] translate.c: Discovered 3 cost path from alaw to slin, via ulaw [2009-03-20 10:16:38] VERBOSE[25812] logger.c: codec_dahdi.so => (Generic DAHDI Transcoder Codec Translator) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format g729, extension(s) g729 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: format_g729.so => (Raw G729 data) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format pcm, extension(s) pcm|ulaw|ul|mu [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format alaw, extension(s) alaw|al [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format au, extension(s) au [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format g722, extension(s) g722 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: format_pcm.so => (Raw/Sun uLaw/ALaw 8KHz (PCM,PCMA,AU), G.722 16Khz) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format wav49, extension(s) WAV|wav49 [2009-03-20 10:16:38] VERBOSE[25812] logger.c: format_wav_gsm.so => (Microsoft WAV format (Proprietary GSM)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered file format wav, extension(s) wav [2009-03-20 10:16:38] VERBOSE[25812] logger.c: format_wav.so => (Microsoft WAV format (8000Hz Signed Linear)) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ChanSpy' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'ExtenSpy' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: app_chanspy.so => (Listen to the audio of an active channel) [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Registered context 'app_dial_gosub_virtual_context'(0x11219f00) in table 0x2aaaac00aa10 registrar: app_dial [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Registered extension context 'app_dial_gosub_virtual_context' (0x11219f00) in table 0x2aaaac00aa10; registrar: app_dial [2009-03-20 10:16:38] DEBUG[25812] pbx.c: Added extension 's' priority 1 to app_dial_gosub_virtual_context (0x11219f00) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: -- Added extension 's' priority 1 to app_dial_gosub_virtual_context (0x11219f00) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'Dial' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'RetryDial' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: app_dial.so => (Dialing Application) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Registered application 'SoftHangup' [2009-03-20 10:16:38] VERBOSE[25812] logger.c: app_softhangup.so => (Hangs up the requested channel) [2009-03-20 10:16:38] VERBOSE[25812] logger.c: Asterisk Ready. [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Parsing '/etc/asterisk/cli.conf': [2009-03-20 10:16:38] DEBUG[25812] config.c: Parsing /etc/asterisk/cli.conf [2009-03-20 10:16:38] VERBOSE[25812] logger.c: == Found [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [2009-03-20 10:16:38] DEBUG[25820] acl.c: Found IP address for this socket [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Initializing initreq for method OPTIONS - callid 184bd8787be1facf218e800e36f6e096@208.34.99.10 [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Stopping retransmission on '184bd8787be1facf218e800e36f6e096@208.34.99.10' of Request 102: Match Found [2009-03-20 10:16:38] DEBUG[25820] devicestate.c: Notification of state change to be queued on device/channel SIP/vocalser2 [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: ---------- SIP HISTORY for '184bd8787be1facf218e800e36f6e096@208.34.99.10' [2009-03-20 10:16:38] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - vocalser2 [2009-03-20 10:16:38] DEBUG[25816] chan_sip.c: Checking device state for peer vocalser2 [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: * SIP Call [2009-03-20 10:16:38] DEBUG[25816] devicestate.c: Changing state for SIP/vocalser2 - state 1 (Not in use) [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: 001. TxReqRel OPTIONS / 102 OPTIONS - -UNKNOWN- [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: 002. Rx SIP/2.0 / 102 OPTIONS / 200 OK [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: ---------- END SIP HISTORY for '184bd8787be1facf218e800e36f6e096@208.34.99.10' [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [2009-03-20 10:16:38] DEBUG[25820] acl.c: Found IP address for this socket [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Initializing initreq for method OPTIONS - callid 7a32dcf40e0eabd34fdd23302273c72e@208.34.99.10 [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 208.34.86.40:5060 [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: Stopping retransmission on '7a32dcf40e0eabd34fdd23302273c72e@208.34.99.10' of Request 102: Match Found [2009-03-20 10:16:38] DEBUG[25820] devicestate.c: Notification of state change to be queued on device/channel SIP/vocalser [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: ---------- SIP HISTORY for '7a32dcf40e0eabd34fdd23302273c72e@208.34.99.10' [2009-03-20 10:16:38] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - vocalser [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: * SIP Call [2009-03-20 10:16:38] DEBUG[25816] chan_sip.c: Checking device state for peer vocalser [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: 001. TxReqRel OPTIONS / 102 OPTIONS - -UNKNOWN- [2009-03-20 10:16:38] DEBUG[25816] devicestate.c: Changing state for SIP/vocalser - state 1 (Not in use) [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: 002. Rx SIP/2.0 / 102 OPTIONS / 200 Options Received [2009-03-20 10:16:38] DEBUG[25820] chan_sip.c: ---------- END SIP HISTORY for '7a32dcf40e0eabd34fdd23302273c72e@208.34.99.10' [2009-03-20 10:16:56] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> INVITE sip:15856982730@208.34.99.10 SIP/2.0 Record-Route: Record-Route: Max-Forwards: 67 Session-Expires: 1800;refresher=uac Supported: timer, 100rel To: 15856982730 From: "Cell Phone NY" ;tag=3446547415-155313 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 1 INVITE Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRIBE, PRACK, UPDATE Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f Contact: Call-Info: ;method="NOTIFY;Event=telephone-event;Duration=1000" Content-Type: application/sdp Content-Length: 335 X-ROUTE-ID: 1 X-DIAL-STRING: SIP/vocalser2/15856982730 v=0 o=02Nextone 9569 9569 IN IP4 64.136.174.30 s=sip call c=IN IP4 64.136.164.68 t=0 0 m=audio 11798 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=sendrecv a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=silenceSupp:off - - - - a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - <-------------> [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 0 [ 43]: INVITE sip:15856982730@208.34.99.10 SIP/2.0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 1 [ 61]: Record-Route: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 2 [ 61]: Record-Route: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 3 [ 16]: Max-Forwards: 67 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 4 [ 35]: Session-Expires: 1800;refresher=uac [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 5 [ 24]: Supported: timer, 100rel [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 6 [ 51]: To: 15856982730 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 7 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 8 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 9 [ 14]: CSeq: 1 INVITE [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 10 [ 97]: Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRIBE, PRACK, UPDATE [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 11 [ 59]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 12 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 13 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 14 [ 56]: Contact: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 15 [ 82]: Call-Info: ;method="NOTIFY;Event=telephone-event;Duration=1000" [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 16 [ 29]: Content-Type: application/sdp [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 17 [ 19]: Content-Length: 335 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 18 [ 13]: X-ROUTE-ID: 1 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 19 [ 40]: X-DIAL-STRING: SIP/vocalser2/15856982730 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 20 [ 0]: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 0 [ 3]: v=0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 1 [ 42]: o=02Nextone 9569 9569 IN IP4 64.136.174.30 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 2 [ 10]: s=sip call [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 3 [ 22]: c=IN IP4 64.136.164.68 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 5 [ 30]: m=audio 11798 RTP/AVP 0 18 101 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 7 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 8 [ 10]: a=sendrecv [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 9 [ 21]: a=rtpmap:18 G729/8000 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 10 [ 19]: a=fmtp:18 annexb=no [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 13 [ 15]: a=fmtp:101 0-16 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Body 14 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:56] VERBOSE[25820] logger.c: --- (20 headers 15 lines) --- [2009-03-20 10:16:56] DEBUG[25820] acl.c: Found IP address for this socket [2009-03-20 10:16:56] VERBOSE[25820] logger.c: == Using SIP RTP CoS mark 5 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: == Using UDPTL CoS mark 5 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Setting NAT on RTP to Off [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Setting NAT on UDPTL to Off [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Allocating new SIP dialog for 23626686-3446547415-155305@02Nextone.globalpops.com - INVITE (With RTP) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Begin: parsing SIP "Supported: timer, 100rel" [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Found SIP option: -timer- [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Matched SIP option: timer [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Found SIP option: -100rel- [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Matched SIP option: 100rel [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Sending to 208.34.86.41 : 5060 (no NAT) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Initializing initreq for method INVITE - callid 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Using INVITE request as basis request - 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:16:56] VERBOSE[25820] logger.c: No user '+15853505727' in SIP users list [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found peer 'vocalser2' for '+15853505727' from 208.34.86.41:5060 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Setting NAT on RTP to Off [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Setting NAT on UDPTL to Off [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found RTP audio format 0 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found RTP audio format 18 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found RTP audio format 101 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Peer doesn't provide T.38 UDPTL [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Peer audio RTP is at port 64.136.164.68:11798 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found audio description format PCMU for ID 0 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found audio description format G729 for ID 18 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Got unsupported a:fmtp in SDP offer [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Found audio description format telephone-event for ID 101 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Got unsupported a:fmtp in SDP offer [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x104 (ulaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x104 (ulaw|g729) [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Peer audio RTP is at port 64.136.164.68:11798 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: We're settling with these formats: 0x104 (ulaw|g729) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Checking SIP call limits for device [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Updating call counter for incoming call [2009-03-20 10:16:56] VERBOSE[25820] logger.c: Looking for 15856982730 in reoriginate (domain 208.34.99.10) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: *** Our native formats are 0x4 (ulaw) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: *** Joint capabilities are 0x104 (ulaw|g729) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: *** Our capabilities are 0x104 (ulaw|g729) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: This channel will not be able to handle video. [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: build_route: Record-Route hop: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: build_route: Record-Route hop: [2009-03-20 10:16:56] VERBOSE[25820] logger.c: list_route: hop: [2009-03-20 10:16:56] VERBOSE[25820] logger.c: list_route: hop: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: SIP/64.136.174.30-ac017aa0: New call is still down.... Trying... [2009-03-20 10:16:56] VERBOSE[25820] logger.c: <--- Transmitting (no NAT) to 208.34.86.41:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1;received=208.34.86.41 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f Record-Route: Record-Route: From: "Cell Phone NY" ;tag=3446547415-155313 To: 15856982730 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 1 INVITE User-Agent: VocalNet Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Length: 0 <------------> [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1;received=208.34.86.41 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 2 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 3 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 4 [ 61]: Record-Route: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 5 [ 61]: Record-Route: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 6 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 7 [ 51]: To: 15856982730 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 8 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 9 [ 14]: CSeq: 1 INVITE [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 10 [ 20]: User-Agent: VocalNet [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 11 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 12 [ 26]: Supported: replaces, timer [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 13 [ 39]: Contact: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 15 [ 0]: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:16:56] DEBUG[25820] devicestate.c: Notification of state change to be queued on device/channel SIP/64.136.174.30 [2009-03-20 10:16:56] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - 64.136.174.30 [2009-03-20 10:16:56] DEBUG[25816] chan_sip.c: Checking device state for peer 64.136.174.30 [2009-03-20 10:16:56] DEBUG[25816] channel.c: Avoiding initial deadlock for channel '0x1121ceb0' [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Function result is '(null)' [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Launching 'Set' [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Executing [15856982730@reoriginate:1] Set("SIP/64.136.174.30-ac017aa0", "cidnum=") in new stack [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Function result is '0' [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Expression result is '0' [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Launching 'GotoIf' [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Executing [15856982730@reoriginate:2] GotoIf("SIP/64.136.174.30-ac017aa0", "0?3:7") in new stack [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Goto (reoriginate,15856982730,7) [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Launching 'NoOp' [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Executing [15856982730@reoriginate:7] NoOp("SIP/64.136.174.30-ac017aa0", "Finish if-reoriginate-1") in new stack [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Function result is '1' [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Launching 'SIPAddHeader' [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Executing [15856982730@reoriginate:8] SIPAddHeader("SIP/64.136.174.30-ac017aa0", "X-ROUTE-ID: 1") in new stack [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: SIP Header added "X-ROUTE-ID: 1" as __SIPADDHEADER01 [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Function result is 'SIP/vocalser2/15856982730' [2009-03-20 10:16:56] DEBUG[25822] pbx.c: Launching 'Dial' [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Executing [15856982730@reoriginate:9] Dial("SIP/64.136.174.30-ac017aa0", "SIP/vocalser2/15856982730") in new stack [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [2009-03-20 10:16:56] VERBOSE[25822] logger.c: == Using SIP RTP CoS mark 5 [2009-03-20 10:16:56] VERBOSE[25822] logger.c: == Using UDPTL CoS mark 5 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Setting NAT on RTP to Off [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Setting NAT on UDPTL to Off [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: OBPROXY: Not applying OBproxy to this call [2009-03-20 10:16:56] DEBUG[25822] acl.c: Found IP address for this socket [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: *** Our native formats are 0x4 (ulaw) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: *** Joint capabilities are 0x4 (ulaw) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: *** Our capabilities are 0x104 (ulaw|g729) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: This channel will not be able to handle video. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable DIALEDTIME. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable ANSWEREDTIME. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable DIALEDPEERNAME. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable DIALEDPEERNUMBER. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable DIALSTATUS. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Copying hard-transferable variable SIPADDHEADER01. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable cidnum. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable SIPCALLID. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable SIPDOMAIN. [2009-03-20 10:16:56] DEBUG[25822] channel.c: Not copying variable SIPURI. [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Outgoing Call for 15856982730 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Updating call counter for outgoing call [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Our T38 capability (3856), joint T38 capability (3856) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Adding SIP Header "X-ROUTE-ID" with content :1: [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: ** Our capability: 0x104 (ulaw|g729) Video flag: False Text flag: False [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [2009-03-20 10:16:56] VERBOSE[25822] logger.c: Audio is at 208.34.99.10 port 13284 [2009-03-20 10:16:56] VERBOSE[25822] logger.c: Adding codec 0x4 (ulaw) to SDP [2009-03-20 10:16:56] VERBOSE[25822] logger.c: Adding codec 0x100 (g729) to SDP [2009-03-20 10:16:56] VERBOSE[25822] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: -- Done with adding codecs to SDP [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Done building SDP. Settling with this capability: 0x104 (ulaw|g729) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Initializing initreq for method INVITE - callid 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 0 [ 43]: INVITE sip:15856982730@208.34.86.41 SIP/2.0 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK6f16dd15;rport [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 3 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 4 [ 34]: To: [2009-03-20 10:16:56] DEBUG[25816] devicestate.c: Changing state for SIP/64.136.174.30 - state 2 (In use) [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 5 [ 40]: Contact: [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 6 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 8 [ 20]: User-Agent: VocalNet [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 9 [ 35]: Date: Fri, 20 Mar 2009 14:16:56 GMT [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 12 [ 13]: X-ROUTE-ID: 1 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 14 [ 19]: Content-Length: 302 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 15 [ 0]: [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 0 [ 3]: v=0 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 1 [ 52]: o=VocalNet 1694828434 1694828434 IN IP4 208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 2 [ 10]: s=VocalNet [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 3 [ 21]: c=IN IP4 208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 5 [ 30]: m=audio 13284 RTP/AVP 0 18 101 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 12 [ 10]: a=ptime:20 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 13 [ 10]: a=sendrecv [2009-03-20 10:16:56] VERBOSE[25822] logger.c: Reliably Transmitting (no NAT) to 208.34.86.41:5060: INVITE sip:15856982730@208.34.86.41 SIP/2.0 Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK6f16dd15;rport Max-Forwards: 70 From: "Cell Phone NY" ;tag=as708a0c2e To: Contact: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 102 INVITE User-Agent: VocalNet Date: Fri, 20 Mar 2009 14:16:56 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer X-ROUTE-ID: 1 Content-Type: application/sdp Content-Length: 302 v=0 o=VocalNet 1694828434 1694828434 IN IP4 208.34.99.10 s=VocalNet c=IN IP4 208.34.99.10 t=0 0 m=audio 13284 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 0 [ 43]: INVITE sip:15856982730@208.34.86.41 SIP/2.0 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK6f16dd15;rport [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 3 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 4 [ 34]: To: [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 5 [ 40]: Contact: [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 6 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 8 [ 20]: User-Agent: VocalNet [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 9 [ 35]: Date: Fri, 20 Mar 2009 14:16:56 GMT [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 12 [ 13]: X-ROUTE-ID: 1 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 14 [ 19]: Content-Length: 302 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Header 15 [ 0]: [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 0 [ 3]: v=0 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 1 [ 52]: o=VocalNet 1694828434 1694828434 IN IP4 208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 2 [ 10]: s=VocalNet [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 3 [ 21]: c=IN IP4 208.34.99.10 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 5 [ 30]: m=audio 13284 RTP/AVP 0 18 101 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 12 [ 10]: a=ptime:20 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Body 13 [ 10]: a=sendrecv [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #9 [2009-03-20 10:16:56] DEBUG[25822] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:16:56] VERBOSE[25822] logger.c: -- Called vocalser2/15856982730 [2009-03-20 10:16:56] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> SIP/2.0 100 Giving a try Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK6f16dd15;rport=5060 From: "Cell Phone NY" ;tag=as708a0c2e To: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 102 INVITE Server: OpenSIPS (1.4.4-notls (i386/linux)) Content-Length: 0 <-------------> [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 0 [ 24]: SIP/2.0 100 Giving a try [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK6f16dd15;rport=5060 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 2 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 3 [ 34]: To: [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 4 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 6 [ 43]: Server: OpenSIPS (1.4.4-notls (i386/linux)) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: Header 8 [ 0]: [2009-03-20 10:16:56] VERBOSE[25820] logger.c: --- (8 headers 0 lines) --- [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: *** SIP TIMER: Cancelling retransmission #9 - INVITE (got response) [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '025059ca740839d55003187667e27a8e@208.34.99.10' Request 102: Found [2009-03-20 10:16:56] DEBUG[25820] chan_sip.c: SIP response 100 to standard invite [2009-03-20 10:16:57] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 208.34.99.10:5060;received=208.34.99.10;branch=z9hG4bK6f16dd15;rport=5060 Record-Route: From: "Cell Phone NY" ;tag=as708a0c2e To: ;tag=as33ce3b1d Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 208.34.99.10:5060;received=208.34.99.10;branch=z9hG4bK6f16dd15;rport=5060 [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 2 [ 54]: Record-Route: [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 3 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 4 [ 49]: To: ;tag=as33ce3b1d [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 5 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 7 [ 24]: User-Agent: Asterisk PBX [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 8 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 9 [ 19]: Supported: replaces [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 10 [ 41]: Contact: [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: Header 12 [ 0]: [2009-03-20 10:16:57] VERBOSE[25820] logger.c: --- (12 headers 0 lines) --- [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '025059ca740839d55003187667e27a8e@208.34.99.10' Request 102: Found [2009-03-20 10:16:57] DEBUG[25820] chan_sip.c: SIP response 180 to standard invite [2009-03-20 10:16:57] DEBUG[25820] devicestate.c: Notification of state change to be queued on device/channel SIP/vocalser2 [2009-03-20 10:16:57] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - vocalser2 [2009-03-20 10:16:57] VERBOSE[25822] logger.c: -- SIP/vocalser2-ac01c090 is ringing [2009-03-20 10:16:57] DEBUG[25816] chan_sip.c: Checking device state for peer vocalser2 [2009-03-20 10:16:57] DEBUG[25816] devicestate.c: Changing state for SIP/vocalser2 - state 1 (Not in use) [2009-03-20 10:16:57] VERBOSE[25822] logger.c: <--- Transmitting (no NAT) to 208.34.86.41:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1;received=208.34.86.41 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f Record-Route: Record-Route: From: "Cell Phone NY" ;tag=3446547415-155313 To: 15856982730 ;tag=as2f711f64 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 1 INVITE User-Agent: VocalNet Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Length: 0 <------------> [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1;received=208.34.86.41 [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 2 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 3 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 4 [ 61]: Record-Route: [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 5 [ 61]: Record-Route: [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 6 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 7 [ 66]: To: 15856982730 ;tag=as2f711f64 [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 8 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 9 [ 14]: CSeq: 1 INVITE [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 10 [ 20]: User-Agent: VocalNet [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 11 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 12 [ 26]: Supported: replaces, timer [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 13 [ 39]: Contact: [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Header 15 [ 0]: [2009-03-20 10:16:57] DEBUG[25822] chan_sip.c: Trying to put 'SIP/2.0 18' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:16:59] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.34.99.10:5060;received=208.34.99.10;branch=z9hG4bK6f16dd15;rport=5060 Record-Route: From: "Cell Phone NY" ;tag=as708a0c2e To: ;tag=as33ce3b1d Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 242 v=0 o=root 1879 1879 IN IP4 208.34.108.155 s=session c=IN IP4 208.34.108.155 t=0 0 m=audio 16596 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 208.34.99.10:5060;received=208.34.99.10;branch=z9hG4bK6f16dd15;rport=5060 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 2 [ 54]: Record-Route: [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 3 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 4 [ 49]: To: ;tag=as33ce3b1d [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 5 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 7 [ 24]: User-Agent: Asterisk PBX [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 8 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 9 [ 19]: Supported: replaces [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 10 [ 41]: Contact: [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 12 [ 19]: Content-Length: 242 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 13 [ 0]: [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 0 [ 3]: v=0 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 1 [ 38]: o=root 1879 1879 IN IP4 208.34.108.155 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 2 [ 9]: s=session [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 3 [ 23]: c=IN IP4 208.34.108.155 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 5 [ 27]: m=audio 16596 RTP/AVP 0 101 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-16 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 9 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 10 [ 10]: a=ptime:20 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Body 11 [ 10]: a=sendrecv [2009-03-20 10:16:59] VERBOSE[25820] logger.c: --- (13 headers 12 lines) --- [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Acked pending invite 102 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Stopping retransmission on '025059ca740839d55003187667e27a8e@208.34.99.10' of Request 102: Match Found [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: SIP response 200 to standard invite [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Found RTP audio format 0 [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Found RTP audio format 101 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Peer doesn't provide T.38 UDPTL [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Peer audio RTP is at port 208.34.108.155:16596 [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Found audio description format PCMU for ID 0 [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Found audio description format telephone-event for ID 101 [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Got unsupported a:fmtp in SDP offer [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Capabilities: us - 0x104 (ulaw|g729), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Peer audio RTP is at port 208.34.108.155:16596 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: We're settling with these formats: 0x4 (ulaw) [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: We have an owner, now see if we need to change this call [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Updating call counter for outgoing call [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: build_route: Record-Route hop: [2009-03-20 10:16:59] VERBOSE[25820] logger.c: list_route: hop: [2009-03-20 10:16:59] VERBOSE[25820] logger.c: set_destination: Parsing for address/port to send to [2009-03-20 10:16:59] VERBOSE[25820] logger.c: set_destination: set destination to 208.34.86.41, port 5060 [2009-03-20 10:16:59] VERBOSE[25820] logger.c: Transmitting (no NAT) to 208.34.86.41:5060: ACK sip:15856982730@208.34.108.155 SIP/2.0 Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK4700ef97;rport Route: Max-Forwards: 70 From: "Cell Phone NY" ;tag=as708a0c2e To: ;tag=as33ce3b1d Contact: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 102 ACK User-Agent: VocalNet Content-Length: 0 --- [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 0 [ 42]: ACK sip:15856982730@208.34.108.155 SIP/2.0 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK4700ef97;rport [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 2 [ 47]: Route: [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 3 [ 16]: Max-Forwards: 70 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 4 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 5 [ 49]: To: ;tag=as33ce3b1d [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 6 [ 40]: Contact: [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 7 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 8 [ 13]: CSeq: 102 ACK [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 9 [ 20]: User-Agent: VocalNet [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Header 11 [ 0]: [2009-03-20 10:16:59] DEBUG[25820] chan_sip.c: Trying to put 'ACK sip:15' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:16:59] DEBUG[25822] devicestate.c: Notification of state change to be queued on device/channel SIP/vocalser2 [2009-03-20 10:16:59] VERBOSE[25822] logger.c: -- SIP/vocalser2-ac01c090 answered SIP/64.136.174.30-ac017aa0 [2009-03-20 10:16:59] DEBUG[25822] devicestate.c: Notification of state change to be queued on device/channel SIP/64.136.174.30 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: SIP answering channel: SIP/64.136.174.30-ac017aa0 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Setting framing from config on incoming call [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: ** Our capability: 0x104 (ulaw|g729) Video flag: True Text flag: True [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [2009-03-20 10:16:59] VERBOSE[25822] logger.c: Audio is at 208.34.99.10 port 12770 [2009-03-20 10:16:59] VERBOSE[25822] logger.c: Adding codec 0x4 (ulaw) to SDP [2009-03-20 10:16:59] VERBOSE[25822] logger.c: Adding codec 0x100 (g729) to SDP [2009-03-20 10:16:59] VERBOSE[25822] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: -- Done with adding codecs to SDP [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Done building SDP. Settling with this capability: 0x104 (ulaw|g729) [2009-03-20 10:16:59] VERBOSE[25822] logger.c: <--- Reliably Transmitting (no NAT) to 208.34.86.41:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1;received=208.34.86.41 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f Record-Route: Record-Route: From: "Cell Phone NY" ;tag=3446547415-155313 To: 15856982730 ;tag=as2f711f64 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 1 INVITE User-Agent: VocalNet Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 302 v=0 o=VocalNet 1348447765 1348447765 IN IP4 208.34.99.10 s=VocalNet c=IN IP4 208.34.99.10 t=0 0 m=audio 12770 RTP/AVP 0 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.1;received=208.34.86.41 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 2 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.0 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 3 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKe8cb9337b14f3fb339e8f353e72e772f [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 4 [ 61]: Record-Route: [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 5 [ 61]: Record-Route: [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 6 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 7 [ 66]: To: 15856982730 ;tag=as2f711f64 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 8 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 9 [ 14]: CSeq: 1 INVITE [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 10 [ 20]: User-Agent: VocalNet [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 11 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 12 [ 26]: Supported: replaces, timer [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 13 [ 39]: Contact: [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 15 [ 19]: Content-Length: 302 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Header 16 [ 0]: [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 0 [ 3]: v=0 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 1 [ 52]: o=VocalNet 1348447765 1348447765 IN IP4 208.34.99.10 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 2 [ 10]: s=VocalNet [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 3 [ 21]: c=IN IP4 208.34.99.10 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 5 [ 30]: m=audio 12770 RTP/AVP 0 18 101 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 7 [ 21]: a=rtpmap:18 G729/8000 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 8 [ 19]: a=fmtp:18 annexb=no [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 12 [ 10]: a=ptime:20 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Body 13 [ 10]: a=sendrecv [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #11 [2009-03-20 10:16:59] DEBUG[25822] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:16:59] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - vocalser2 [2009-03-20 10:16:59] DEBUG[25816] chan_sip.c: Checking device state for peer vocalser2 [2009-03-20 10:16:59] DEBUG[25816] devicestate.c: Changing state for SIP/vocalser2 - state 1 (Not in use) [2009-03-20 10:16:59] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - 64.136.174.30 [2009-03-20 10:16:59] DEBUG[25816] chan_sip.c: Checking device state for peer 64.136.174.30 [2009-03-20 10:16:59] DEBUG[25816] devicestate.c: Changing state for SIP/64.136.174.30 - state 2 (In use) [2009-03-20 10:17:00] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> ACK sip:15856982730@208.34.99.10 SIP/2.0 Max-Forwards: 67 To: 15856982730 ;tag=as2f711f64 From: "Cell Phone NY" ;tag=3446547415-155313 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 1 ACK Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRIBE, PRACK, UPDATE Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.3 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.2 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKda8b9a3ba5476173ad6534b9d7aaa5ae Contact: Content-Length: 0 <-------------> [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 0 [ 40]: ACK sip:15856982730@208.34.99.10 SIP/2.0 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 1 [ 16]: Max-Forwards: 67 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 2 [ 66]: To: 15856982730 ;tag=as2f711f64 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 3 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 4 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 5 [ 11]: CSeq: 1 ACK [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 6 [ 97]: Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRIBE, PRACK, UPDATE [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 7 [ 59]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK804e.3ef16523.3 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 8 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK804e.620ec7c2.2 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 9 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bKda8b9a3ba5476173ad6534b9d7aaa5ae [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 10 [ 56]: Contact: [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Header 12 [ 0]: [2009-03-20 10:17:00] VERBOSE[25820] logger.c: --- (12 headers 0 lines) --- [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #11 [2009-03-20 10:17:00] DEBUG[25820] chan_sip.c: Stopping retransmission on '23626686-3446547415-155305@02Nextone.globalpops.com' of Response 1: Match Found [2009-03-20 10:17:00] DEBUG[25822] features.c: bridge answer set, chan answer set [2009-03-20 10:17:00] VERBOSE[25822] logger.c: -- Packet2Packet bridging SIP/64.136.174.30-ac017aa0 and SIP/vocalser2-ac01c090 [2009-03-20 10:17:05] DEBUG[25822] rtp.c: Got RTCP report of 64 bytes [2009-03-20 10:17:06] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> BYE sip:15856982730@208.34.99.10 SIP/2.0 Max-Forwards: 67 To: 15856982730 ;tag=as2f711f64 From: "Cell Phone NY" ;tag=3446547415-155313 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 2 BYE Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRIBE, PRACK, UPDATE Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK504e.b7bf24a2.0 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK504e.8e4f8942.0 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bK8ad7a7fbf3b2061212438b3199081e73 Contact: Content-Length: 0 <-------------> [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 0 [ 40]: BYE sip:15856982730@208.34.99.10 SIP/2.0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 1 [ 16]: Max-Forwards: 67 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 2 [ 66]: To: 15856982730 ;tag=as2f711f64 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 3 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 4 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 5 [ 11]: CSeq: 2 BYE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 6 [ 97]: Allow: INVITE, BYE, OPTIONS, CANCEL, ACK, REGISTER, NOTIFY, INFO, REFER, SUBSCRIBE, PRACK, UPDATE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 7 [ 59]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK504e.b7bf24a2.0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 8 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK504e.8e4f8942.0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 9 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bK8ad7a7fbf3b2061212438b3199081e73 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 10 [ 56]: Contact: [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 12 [ 0]: [2009-03-20 10:17:06] VERBOSE[25820] logger.c: --- (12 headers 0 lines) --- [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Initializing initreq for method BYE - callid 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:17:06] VERBOSE[25820] logger.c: Sending to 208.34.86.41 : 5060 (no NAT) [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Setting SIP_ALREADYGONE on dialog 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Received bye, issuing owner hangup [2009-03-20 10:17:06] VERBOSE[25820] logger.c: <--- Transmitting (no NAT) to 208.34.86.41:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK504e.b7bf24a2.0;received=208.34.86.41 Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK504e.8e4f8942.0 Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bK8ad7a7fbf3b2061212438b3199081e73 From: "Cell Phone NY" ;tag=3446547415-155313 To: 15856982730 ;tag=as2f711f64 Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com CSeq: 2 BYE User-Agent: VocalNet Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Length: 0 <------------> [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 208.34.86.41;branch=z9hG4bK504e.b7bf24a2.0;received=208.34.86.41 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 2 [ 59]: Via: SIP/2.0/UDP 208.34.86.40;branch=z9hG4bK504e.8e4f8942.0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 3 [ 82]: Via: SIP/2.0/UDP 64.136.174.30:5060;branch=z9hG4bK8ad7a7fbf3b2061212438b3199081e73 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 4 [ 78]: From: "Cell Phone NY" ;tag=3446547415-155313 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 5 [ 66]: To: 15856982730 ;tag=as2f711f64 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 6 [ 60]: Call-ID: 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 7 [ 11]: CSeq: 2 BYE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 8 [ 20]: User-Agent: VocalNet [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 9 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 12 [ 0]: [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:17:06] DEBUG[25822] rtp.c: p2p-rtp-bridge: Ooh, got a hangup [2009-03-20 10:17:06] DEBUG[25822] channel.c: Returning from native bridge, channels: SIP/64.136.174.30-ac017aa0, SIP/vocalser2-ac01c090 [2009-03-20 10:17:06] DEBUG[25822] channel.c: Hanging up channel 'SIP/vocalser2-ac01c090' [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Hangup call SIP/vocalser2-ac01c090, SIP callid 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:17:06] VERBOSE[25822] logger.c: Scheduling destruction of SIP dialog '025059ca740839d55003187667e27a8e@208.34.99.10' in 6400 ms (Method: INVITE) [2009-03-20 10:17:06] VERBOSE[25822] logger.c: set_destination: Parsing for address/port to send to [2009-03-20 10:17:06] VERBOSE[25822] logger.c: set_destination: set destination to 208.34.86.41, port 5060 [2009-03-20 10:17:06] VERBOSE[25822] logger.c: Reliably Transmitting (no NAT) to 208.34.86.41:5060: BYE sip:15856982730@208.34.108.155 SIP/2.0 Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK5f4cf993;rport Route: Max-Forwards: 70 From: "Cell Phone NY" ;tag=as708a0c2e To: ;tag=as33ce3b1d Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 103 BYE User-Agent: VocalNet X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 0 [ 42]: BYE sip:15856982730@208.34.108.155 SIP/2.0 [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 208.34.99.10:5060;branch=z9hG4bK5f4cf993;rport [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 2 [ 47]: Route: [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 3 [ 16]: Max-Forwards: 70 [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 4 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 5 [ 49]: To: ;tag=as33ce3b1d [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 6 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 7 [ 13]: CSeq: 103 BYE [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 8 [ 20]: User-Agent: VocalNet [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 9 [ 39]: X-Asterisk-HangupCause: Normal Clearing [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 10 [ 30]: X-Asterisk-HangupCauseCode: 16 [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Header 12 [ 0]: [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #14 [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Trying to put 'BYE sip:15' onto UDP socket destined for 208.34.86.41:5060 [2009-03-20 10:17:06] DEBUG[25822] devicestate.c: Notification of state change to be queued on device/channel SIP/vocalser2 [2009-03-20 10:17:06] DEBUG[25822] rtp.c: Channel '' has no RTP, not doing anything [2009-03-20 10:17:06] DEBUG[25822] app_dial.c: Exiting with DIALSTATUS=ANSWER. [2009-03-20 10:17:06] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - vocalser2 [2009-03-20 10:17:06] DEBUG[25822] pbx.c: Spawn extension (reoriginate,15856982730,9) exited non-zero on 'SIP/64.136.174.30-ac017aa0' [2009-03-20 10:17:06] DEBUG[25816] chan_sip.c: Checking device state for peer vocalser2 [2009-03-20 10:17:06] DEBUG[25816] devicestate.c: Changing state for SIP/vocalser2 - state 1 (Not in use) [2009-03-20 10:17:06] VERBOSE[25822] logger.c: == Spawn extension (reoriginate, 15856982730, 9) exited non-zero on 'SIP/64.136.174.30-ac017aa0' [2009-03-20 10:17:06] DEBUG[25822] channel.c: Soft-Hanging up channel 'SIP/64.136.174.30-ac017aa0' [2009-03-20 10:17:06] DEBUG[25822] channel.c: Hanging up channel 'SIP/64.136.174.30-ac017aa0' [2009-03-20 10:17:06] DEBUG[25822] chan_sip.c: Hangup call SIP/64.136.174.30-ac017aa0, SIP callid 23626686-3446547415-155305@02Nextone.globalpops.com [2009-03-20 10:17:06] DEBUG[25822] devicestate.c: Notification of state change to be queued on device/channel SIP/64.136.174.30 [2009-03-20 10:17:06] DEBUG[25816] devicestate.c: No provider found, checking channel drivers for SIP - 64.136.174.30 [2009-03-20 10:17:06] DEBUG[25816] chan_sip.c: Checking device state for peer 64.136.174.30 [2009-03-20 10:17:06] DEBUG[25816] devicestate.c: Changing state for SIP/64.136.174.30 - state 1 (Not in use) [2009-03-20 10:17:06] VERBOSE[25820] logger.c: <--- SIP read from UDP://208.34.86.41:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 208.34.99.10:5060;received=208.34.99.10;branch=z9hG4bK5f4cf993;rport=5060 From: "Cell Phone NY" ;tag=as708a0c2e To: ;tag=as33ce3b1d Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 CSeq: 103 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <-------------> [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 208.34.99.10:5060;received=208.34.99.10;branch=z9hG4bK5f4cf993;rport=5060 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 2 [ 70]: From: "Cell Phone NY" ;tag=as708a0c2e [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 3 [ 49]: To: ;tag=as33ce3b1d [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 4 [ 54]: Call-ID: 025059ca740839d55003187667e27a8e@208.34.99.10 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 5 [ 13]: CSeq: 103 BYE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 6 [ 24]: User-Agent: Asterisk PBX [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 7 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 8 [ 19]: Supported: replaces [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 9 [ 41]: Contact: [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Header 11 [ 0]: [2009-03-20 10:17:06] VERBOSE[25820] logger.c: --- (11 headers 0 lines) --- [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: Stopping retransmission on '025059ca740839d55003187667e27a8e@208.34.99.10' of Request 103: Match Found [2009-03-20 10:17:06] VERBOSE[25820] logger.c: Really destroying SIP dialog '025059ca740839d55003187667e27a8e@208.34.99.10' Method: INVITE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: ---------- SIP HISTORY for '025059ca740839d55003187667e27a8e@208.34.99.10' [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: * SIP Call [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 001. NewChan Channel SIP/vocalser2-ac01c090 - from 025059ca740839d5500318766 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 002. TxReqRel INVITE / 102 INVITE - -UNKNOWN- [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 003. Rx SIP/2.0 / 102 INVITE / 100 Giving a try [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 004. Rx SIP/2.0 / 102 INVITE / 180 Ringing [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 005. Rx SIP/2.0 / 102 INVITE / 200 OK [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 006. TxReq ACK / 102 ACK - -UNKNOWN- [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 007. Hangup Cause Normal Clearing [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 008. SchedDestroy 6400 ms [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 009. TxReqRel BYE / 103 BYE - -UNKNOWN- [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 010. RTCPaudio Quality:ssrc=1442281571;themssrc=0;lp=0;rxjitter=0.000000;rxcou [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 011. Rx SIP/2.0 / 103 BYE / 200 OK [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: ---------- END SIP HISTORY for '025059ca740839d55003187667e27a8e@208.34.99.10' [2009-03-20 10:17:06] VERBOSE[25820] logger.c: Really destroying SIP dialog '23626686-3446547415-155305@02Nextone.globalpops.com' Method: BYE [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: ---------- SIP HISTORY for '23626686-3446547415-155305@02Nextone.globalpops.com' [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: * SIP Call [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 001. Rx INVITE / 1 INVITE / sip:15856982730@208.34.99.10 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 002. NewChan Channel SIP/64.136.174.30-ac017aa0 - from 23626686-3446547415-1 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 003. TxResp SIP/2.0 / 1 INVITE - 100 Trying [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 004. TxResp SIP/2.0 / 1 INVITE - 180 Ringing [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 005. TxRespRel SIP/2.0 / 1 INVITE - 200 OK [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 006. Rx ACK / 1 ACK / sip:15856982730@208.34.99.10 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 007. Rx BYE / 2 BYE / sip:15856982730@208.34.99.10 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 008. RTCPaudio Quality:ssrc=1936005620;themssrc=1407731359;lp=0;rxjitter=0.000 [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 009. TxResp SIP/2.0 / 2 BYE - 200 OK [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: 010. Hangup Cause Normal Clearing [2009-03-20 10:17:06] DEBUG[25820] chan_sip.c: ---------- END SIP HISTORY for '23626686-3446547415-155305@02Nextone.globalpops.com' [2009-03-20 10:17:14] VERBOSE[25821] logger.c: Beginning asterisk shutdown.... [2009-03-20 10:17:14] VERBOSE[25821] logger.c: Executing last minute cleanups [2009-03-20 10:17:14] VERBOSE[25821] logger.c: Asterisk cleanly ending (0). [2009-03-20 10:17:14] DEBUG[25821] asterisk.c: Asterisk ending (0).