[root@foxtrot asterisk]# asterisk -vvvvc == Parsing '/etc/asterisk/asterisk.conf': Found == Parsing '/etc/asterisk/extconfig.conf': Found Asterisk SVN-trunk-r35555M, Copyright (C) 1999 - 2006 Digium, Inc. and others. Created by Mark Spencer Asterisk comes with ABSOLUTELY NO WARRANTY; type 'show warranty' for details. This is free software, with components licensed under the GNU General Public License version 2 and other licenses; you are welcome to redistribute it under certain conditions. Type 'show license' for details. ========================================================================= == Parsing '/etc/asterisk/logger.conf': Found Asterisk Event Logger Started /var/log/asterisk/event_log == Parsing '/etc/asterisk/dnsmgr.conf': Found Asterisk Dynamic Loader loading preload modules: == Parsing '/etc/asterisk/modules.conf': Found [res_odbc.so] => (ODBC Resource) == Parsing '/etc/asterisk/res_odbc.conf': Found Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:220 load_odbc_config: Adding ENV var: INFORMIXSERVER=my_special_database Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:220 load_odbc_config: Adding ENV var: INFORMIXDIR=/opt/informix Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:220 load_odbc_config: Adding ENV var: ODBCINI=/etc/odbc.ini Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:490 odbc_obj_connect: Connecting debtnet Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:504 odbc_obj_connect: res_odbc: Connected to debtnet [debtnet] Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:292 load_odbc_config: Registered ODBC class 'debtnet' dsn->[debtnet] Jun 22 23:02:28 NOTICE[30900]: res_odbc.c:667 load_module: res_odbc loaded. [res_config_odbc.so] => (ODBC Configuration) Jun 22 23:02:28 NOTICE[30900]: config.c:854 ast_config_engine_register: Registered Config Engine odbc res_config_odbc loaded. Jun 22 23:02:28 DEBUG[30900]: loader.c:389 fixup: ---- fixup (load_modules): 2 modules, 0 new --- Jun 22 23:02:28 DEBUG[30900]: loader.c:394 fixup: ---- fixup: cycle 0 --- Jun 22 23:02:28 DEBUG[30900]: loader.c:425 fixup: ---- fixup complete --- == Parsing '/etc/asterisk/http.conf': Found == Manager registered action Ping == Manager registered action Events == Manager registered action Logoff == Manager registered action Hangup == Manager registered action Status == Manager registered action Setvar == Manager registered action Getvar == Manager registered action Redirect == Manager registered action Originate == Manager registered action Command == Manager registered action ExtensionState == Manager registered action AbsoluteTimeout == Manager registered action MailboxStatus == Manager registered action MailboxCount == Manager registered action ListCommands == Manager registered action UserEvent == Manager registered action WaitEvent == Parsing '/etc/asterisk/manager.conf': Found Asterisk Management interface listening on port 5038 == Parsing '/etc/asterisk/cdr.conf': Found Jun 22 23:02:28 NOTICE[30900]: cdr.c:1093 do_reload: CDR simple logging enabled. == Parsing '/etc/asterisk/rtp.conf': Found == RTP Allocating from port range 10000 -> 20000 == Parsing '/etc/asterisk/udptl.conf': Found == UDPTL allocating from port range 4000 -> 4999 Asterisk PBX Core Initializing Registering builtin applications: [Answer] == Registered application 'Answer' [BackGround] == Registered application 'BackGround' [Busy] == Registered application 'Busy' [Congestion] == Registered application 'Congestion' [Goto] == Registered application 'Goto' [GotoIf] == Registered application 'GotoIf' [GotoIfTime] == Registered application 'GotoIfTime' [ExecIfTime] == Registered application 'ExecIfTime' [Hangup] == Registered application 'Hangup' [NoOp] == Registered application 'NoOp' [Progress] == Registered application 'Progress' [ResetCDR] == Registered application 'ResetCDR' [Ringing] == Registered application 'Ringing' [SayNumber] == Registered application 'SayNumber' [SayDigits] == Registered application 'SayDigits' [SayAlpha] == Registered application 'SayAlpha' [SayPhonetic] == Registered application 'SayPhonetic' [SetAMAFlags] == Registered application 'SetAMAFlags' [SetGlobalVar] == Registered application 'SetGlobalVar' [Set] == Registered application 'Set' [ImportVar] == Registered application 'ImportVar' [Wait] == Registered application 'Wait' [WaitExten] == Registered application 'WaitExten' Asterisk Dynamic Loader Starting: == Parsing '/etc/asterisk/modules.conf': Found [res_musiconhold.so] => (Music On Hold Resource) == Registered application 'MusicOnHold' == Registered application 'WaitMusicOnHold' == Registered application 'SetMusicOnHold' == Registered application 'StartMusicOnHold' == Registered application 'StopMusicOnHold' == Parsing '/etc/asterisk/musiconhold.conf': Found [res_convert.so] => (File format conversion CLI command) [res_jabber.so] => (AJI - Asterisk JABBER Interface) == Parsing '/etc/asterisk/jabber.conf': Found == Registered application 'JABBERSend' == Registered application 'JABBERStatus' Jun 22 23:02:28 NOTICE[30900]: res_jabber.c:2282 load_module: res_jabber.so loaded. [res_config_pgsql.so]JABBER: reconnecting. => (Postgresql RealTime Configuration Driver) Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:687 parse_config: Postgresql RealTime Host: Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:688 parse_config: Postgresql RealTime Port: 5432 Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:692 parse_config: Postgresql RealTime User: Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:693 parse_config: Postgresql RealTime Password: Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:694 parse_config: Postgresql RealTime DBName: Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:749 pgsql_reconnect: 100 connInfo=host= port=5432 dbname= user= password= Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:751 pgsql_reconnect: 100 connInfo=host= port=5432 dbname= user= password= Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:754 pgsql_reconnect: pgsqlConn=0x8874738 Jun 22 23:02:28 DEBUG[30900]: res_config_pgsql.c:756 pgsql_reconnect: Postgresql RealTime: Successfully connected to database. Jun 22 23:02:28 NOTICE[30900]: config.c:854 ast_config_engine_register: Registered Config Engine pgsql Postgresql RealTime driver loaded. [res_agi.so] => (Asterisk Gateway Interface (AGI)) == Registered application 'DeadAGI' == Registered application 'EAGI' == Registered application 'AGI' [res_adsi.so] => (ADSI Resource) == Parsing '/etc/asterisk/adsi.conf': Found [res_indications.so] => (Indications Configuration) == Parsing '/etc/asterisk/indications.conf': Found -- Registered indication country 'at' -- Registered indication country 'au' -- Registered indication country 'br' -- Registered indication country 'be' -- Registered indication country 'ch' -- Registered indication country 'cl' -- Registered indication country 'cn' -- Registered indication country 'cz' -- Registered indication country 'de' -- Registered indication country 'dk' -- Registered indication country 'ee' -- Registered indication country 'es' -- Registered indication country 'fi' -- Registered indication country 'fr' -- Registered indication country 'gr' -- Registered indication country 'hu' -- Registered indication country 'it' -- Registered indication country 'lt' -- Registered indication country 'mx' -- Registered indication country 'my' -- Registered indication country 'nl' -- Registered indication country 'no' -- Registered indication country 'nz' -- Registered indication country 'pl' -- Registered indication country 'pt' -- Registered indication country 'ru' -- Registered indication country 'se' -- Registered indication country 'sg' -- Registered indication country 'th' -- Registered indication country 'uk' -- Registered indication country 'us' -- Registered indication country 'us-o' -- Registered indication country 'tw' -- Registered indication country 'za' -- Setting default indication country to 'us' == Registered application 'PlayTones' == Registered application 'StopPlayTones' [res_speech.so] => (Generic Speech Recognition API) [res_clioriginate.so] => (Call origination from the CLI) [res_features.so] => (Call Features Resource) == Parsing '/etc/asterisk/features.conf': Found -- Registered extension context 'parkedcalls' -- Added extension '700' priority 1 to parkedcalls == Registered application 'ParkedCall' == Registered application 'Park' == Manager registered action ParkedCalls == Manager registered action Park [res_smdi.so] => (Asterisk Simplified Message Desk Interface (SMDI) Module) == Parsing '/etc/asterisk/smdi.conf': Found Jun 22 23:02:28 WARNING[30900]: res_smdi.c:729 load_module: No SMDI interfaces are available to listen on, not starting SDMI listener. [res_crypto.so] => (Cryptographic Digital Signatures) -- Loaded PUBLIC key 'iaxtel' -- Loaded PUBLIC key 'freeworlddialup' [res_monitor.so] => (Call Monitoring Resource) == Registered application 'Monitor' == Registered application 'StopMonitor' == Registered application 'ChangeMonitor' == Registered application 'PauseMonitor' == Registered application 'UnpauseMonitor' == Manager registered action Monitor == Manager registered action StopMonitor == Manager registered action ChangeMonitor == Manager registered action PauseMonitor == Manager registered action UnpauseMonitor [pbx_config.so] => (Text Extension Configuration) == Parsing '/etc/asterisk/extensions.conf': Found == Parsing '/etc/asterisk/qdialplan.conf': Found == Setting global variable 'CONSOLE' to 'Console/dsp' -- Registered extension context 'phrase-menu' -- Added extension '1' priority 1 to phrase-menu -- Added extension '1' priority 2 to phrase-menu -- Added extension '1' priority 3 to phrase-menu -- Added extension '1' priority 4 to phrase-menu -- Added extension '1' priority 5 to phrase-menu -- Added extension '1' priority 6 to phrase-menu -- Added extension '2' priority 1 to phrase-menu -- Added extension '2' priority 2 to phrase-menu -- Added extension '2' priority 3 to phrase-menu -- Added extension '2' priority 4 to phrase-menu -- Added extension 'i' priority 1 to phrase-menu -- Added extension 'i' priority 2 to phrase-menu -- Added extension 's' priority 1 to phrase-menu -- Added extension 's' priority 2 to phrase-menu -- Added extension 's' priority 3 to phrase-menu -- Added extension 's' priority 4 to phrase-menu -- Added extension 't' priority 1 to phrase-menu -- Registered extension context 'isdn10' -- Added extension '611734' priority 1 (CID match '08005875290')to isdn10 -- Added extension '611734' priority 2 (CID match '08005875290')to isdn10 -- Added extension '611734' priority 3 (CID match '08005875290')to isdn10 -- Added extension '611734' priority 4 (CID match '08005875290')to isdn10 -- Added extension '444611' priority 1 (CID match '08005875290')to isdn10 -- Added extension '444611' priority 2 (CID match '08005875290')to isdn10 -- Added extension '444611' priority 3 (CID match '08005875290')to isdn10 -- Added extension '444611' priority 4 (CID match '08005875290')to isdn10 -- Added extension '_4446XX' priority 1 to isdn10 -- Added extension 'fax' priority 1 to isdn10 -- Registered extension context 'from-sip' -- Including context 'common' in context 'from-sip' -- Added extension '_**6XX' priority 1 to from-sip -- Added extension '_**6XX' priority 2 to from-sip -- Added extension '_**6XX' priority 3 to from-sip -- Added extension '_0.' priority 1 to from-sip -- Added extension '_0.' priority 2 to from-sip -- Added extension '_0.' priority 3 to from-sip -- Added extension '_XXXXXX' priority 1 to from-sip -- Added extension '_XXXXXX' priority 2 to from-sip -- Added extension '_XXXXXX' priority 3 to from-sip -- Added extension 'h' priority 1 to from-sip -- Added extension 'h' priority 2 to from-sip -- Registered extension context 'common' -- Added extension '779' priority 1 to common -- Added extension '701' priority 1 to common -- Added extension '702' priority 1 to common -- Added extension '703' priority 1 to common -- Added extension '703' priority 2 to common -- Added extension '703' priority 3 to common -- Added extension '704' priority 1 to common -- Added extension '704' priority 2 to common -- Added extension '704' priority 3 to common -- Added extension '704' priority 4 to common -- Added extension '704' priority 5 to common -- Added extension '704' priority 6 to common -- Added extension '704' priority 7 to common -- Added extension '705' priority 1 to common -- Added extension '705' priority 2 to common -- Added extension '705' priority 3 to common -- Added extension '705' priority 4 to common -- Added extension '705' priority 5 to common -- Added extension '705' priority 6 to common -- Added extension '711' priority 1 to common -- Added extension '711' priority 2 to common -- Added extension '714' priority 1 to common -- Added extension '714' priority 2 to common -- Added extension '715' priority 1 to common -- Added extension '715' priority 2 to common -- Added extension '7066' priority 1 to common -- Added extension '7066' priority 2 to common -- Added extension '7067' priority 1 to common -- Added extension '7067' priority 2 to common -- Added extension '_7XX' priority 1 to common -- Added extension '_7XX' priority 2 to common -- Added extension '_7XX' priority 3 to common -- Added extension '806' priority 1 to common -- Added extension '807' priority 1 to common -- Added extension '807' priority 2 to common -- Added extension '807' priority 3 to common -- Added extension '807' priority 4 to common -- Added extension '807' priority 5 to common -- Registered extension context 'fax' -- Registered extension context 'AgentQ' -- Added extension '_X.' priority 1 to AgentQ -- Added extension '_X.' priority 2 to AgentQ -- Added extension '_X.' priority 3 to AgentQ -- Added extension '_X.' priority 4 to AgentQ -- Added extension '_X.' priority 5 to AgentQ -- Added extension '_X.' priority 6 to AgentQ -- Added extension '_X.' priority 7 to AgentQ -- Added extension '_X.' priority 8 to AgentQ -- Added extension '_X.' priority 9 to AgentQ -- Added extension '_X.' priority 10 to AgentQ -- Added extension 'h' priority 1 to AgentQ -- Registered extension context 'from-debtnet' -- Added extension '_X.' priority 1 to from-debtnet -- Added extension '_X.' priority 2 to from-debtnet -- Added extension '_X.' priority 3 to from-debtnet -- Added extension '_X.' priority 4 to from-debtnet -- Added extension '_X.' priority 5 to from-debtnet -- Added extension '_X.' priority 6 to from-debtnet -- Added extension '_X.' priority 7 to from-debtnet -- Added extension '_X.' priority 8 to from-debtnet -- Added extension '_X.' priority 9 to from-debtnet -- Added extension 'h' priority 1 to from-debtnet -- Added extension 'h' priority 2 to from-debtnet -- Registered extension context 'DialResult' -- Added extension 'r1' priority 1 to DialResult -- Added extension 'r1' priority 2 to DialResult -- Added extension 'r16' priority 1 to DialResult -- Added extension 'r17' priority 1 to DialResult -- Added extension 'r18' priority 1 to DialResult -- Added extension 'r18' priority 2 to DialResult -- Added extension 'r18' priority 3 to DialResult -- Added extension 'r19' priority 1 to DialResult -- Added extension 'r19' priority 2 to DialResult -- Added extension 'r27' priority 1 to DialResult -- Added extension 'r27' priority 2 to DialResult -- Added extension 'r28' priority 1 to DialResult -- Added extension 'r28' priority 2 to DialResult -- Added extension 'r31' priority 1 to DialResult -- Added extension 'r31' priority 2 to DialResult -- Added extension 'r34' priority 1 to DialResult -- Added extension 'r34' priority 2 to DialResult -- Added extension 'r41' priority 1 to DialResult -- Added extension 'r41' priority 2 to DialResult -- Added extension 'r41' priority 3 to DialResult -- Added extension 'r42' priority 1 to DialResult -- Added extension 'r42' priority 2 to DialResult -- Added extension 'r63' priority 1 to DialResult -- Added extension 'r63' priority 2 to DialResult -- Added extension 'i' priority 1 to DialResult -- Added extension 'i' priority 2 to DialResult -- Added extension 'i' priority 3 to DialResult -- Added extension 'i' priority 4 to DialResult -- Added extension 'i' priority 5 to DialResult -- Registered extension context 'macro-DialExternal' -- Added extension 's' priority 1 to macro-DialExternal -- Added extension 's' priority 2 to macro-DialExternal -- Added extension 's' priority 3 to macro-DialExternal -- Added extension 's' priority 4 to macro-DialExternal -- Added extension 's' priority 5 to macro-DialExternal -- Added extension 'h' priority 1 to macro-DialExternal -- Registered extension context 'macro-connected' -- Added extension 's' priority 2 to macro-connected -- Registered extension context 'macro-AgentConnected' -- Added extension 's' priority 1 to macro-AgentConnected -- Added extension 's' priority 2 to macro-AgentConnected -- Added extension 's' priority 3 to macro-AgentConnected -- Registered extension context 'macro-callq' -- Added extension 's' priority 1 to macro-callq -- Added extension 's' priority 2 to macro-callq -- Added extension 's' priority 3 to macro-callq -- Added extension 's' priority 4 to macro-callq -- Added extension 's' priority 5 to macro-callq -- Added extension 's' priority 6 to macro-callq -- Added extension 's' priority 7 to macro-callq -- Added extension 's' priority 8 to macro-callq -- Added extension 's' priority 9 to macro-callq -- Added extension 's' priority 10 to macro-callq -- Added extension 's' priority 11 to macro-callq -- Added extension 's' priority 12 to macro-callq -- Added extension 's' priority 13 to macro-callq -- Added extension 's' priority 14 to macro-callq -- Added extension 's' priority 15 to macro-callq -- Added extension 's' priority 16 to macro-callq -- Added extension 's' priority 17 to macro-callq -- Added extension 's' priority 18 to macro-callq -- Added extension 's' priority 19 to macro-callq -- Added extension 's' priority 20 to macro-callq -- Added extension 's' priority 21 to macro-callq -- Added extension 'h' priority 1 to macro-callq -- Added extension 'h' priority 2 to macro-callq -- Added extension 'h' priority 3 to macro-callq -- Added extension 'h' priority 4 to macro-callq Jun 22 23:02:29 DEBUG[30900]: pbx.c:3510 ast_merge_contexts_and_delete: must remove any reg pbx_config Jun 22 23:02:29 DEBUG[30900]: pbx.c:4845 __ast_context_destroy: check ctx parkedcalls res_features [pbx_spool.so] => (Outgoing Spool Support) [pbx_loopback.so] => (Loopback Switch) [pbx_ael.so] => (Asterisk Extension Language Compiler v2) Jun 22 23:02:29 NOTICE[30900]: pbx_ael.c:3453 pbx_load_module: Starting AEL load process. Jun 22 23:02:31 NOTICE[30900]: pbx_ael.c:3460 pbx_load_module: AEL load process: calculated config file name '/etc/asterisk/extensions.ael'. Jun 22 23:02:31 ERROR[30900]: ael.flex:558 ael2_parse: File /etc/asterisk/extensions.ael could not be opened Jun 22 23:02:31 NOTICE[30900]: pbx_ael.c:3463 pbx_load_module: AEL load process: parsed config file name '/etc/asterisk/extensions.ael'. Jun 22 23:02:31 ERROR[30900]: pbx_ael.c:3476 pbx_load_module: Sorry, but 1 syntax errors and 0 semantic errors were detected. It doesn't make sense to compile. [pbx_realtime.so] => (Realtime Switch) [pbx_dundi.so] => (Distributed Universal Number Discovery (DUNDi)) == Parsing '/etc/asterisk/dundi.conf': Found Jun 22 23:02:31 DEBUG[30900]: pbx_dundi.c:408 reset_global_eid: Seeding global EID '00:12:79:3c:c9:10' from 'eth0' == Using TOS bits 0 == DUNDi Ready and Listening on 0.0.0.0 port 4520 == Registered custom function DUNDILOOKUP [chan_features.so] => (Feature Proxy Channel) == Registered channel type 'Feature' (Feature Proxy Channel Driver) [chan_phone.so] => (Linux Telephony API Support) == Parsing '/etc/asterisk/phone.conf': Found == Registered channel type 'Phone' (Standard Linux Telephony API Driver) [chan_skinny.so] => (Skinny Client Control Protocol (Skinny)) == Parsing '/etc/asterisk/skinny.conf': Found Jun 22 23:02:31 WARNING[30900]: chan_skinny.c:4124 reload_config: Option 'port' at line 5 of skinny.conf has been deprecated. Please use 'bindport' instead. == Skinny listening on 0.0.0.0:2000 == Registered channel type 'Skinny' (Skinny Client Control Protocol (Skinny)) [chan_agent.so] => (Agent Proxy Channel) == Registered channel type 'Agent' (Call Agent Proxy Channel) == Registered application 'AgentLogin' == Registered application 'AgentCallbackLogin' == Registered application 'AgentMonitorOutgoing' == Manager registered action Agents == Manager registered action AgentLogoff == Manager registered action AgentCallbackLogin == Registered custom function AGENT == Parsing '/etc/asterisk/agents.conf': Found [chan_local.so] => (Local Proxy Channel) == Registered channel type 'Local' (Local Proxy Channel Driver) [chan_zap.so] => (Zapata Telephony) == Registered application 'ZapSendKeypadFacility' == Parsing '/etc/asterisk/zapata.conf': Found Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 1, with 0 conference users -- Registered channel 1, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 2, with 0 conference users -- Registered channel 2, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 3, with 0 conference users -- Registered channel 3, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 4, with 0 conference users -- Registered channel 4, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 5, with 0 conference users -- Registered channel 5, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 6, with 0 conference users -- Registered channel 6, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 7, with 0 conference users -- Registered channel 7, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 8, with 0 conference users -- Registered channel 8, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 9, with 0 conference users -- Registered channel 9, PRI Signalling signalling Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 22 23:02:31 DEBUG[30900]: chan_zap.c:1357 update_conf: Updated conferencing on 10, with 0 conference users -- Registered channel 10, PRI Signalling signalling -- Automatically generated pseudo channel == Starting D-Channel on span 1 == Registered channel type 'Zap' (Zapata Telephony Driver w/PRI) == Manager registered action ZapTransfer == Manager registered action ZapHangup == Manager registered action ZapDialOffhook == Manager registered action ZapDNDon == Manager registered action ZapDNDoff == Manager registered action ZapShowChannels == Manager registered action ZapRestart [chan_mgcp.so] => (Media Gateway Control Protocol (MGCP)) == Parsing '/etc/asterisk/mgcp.conf': Found == MGCP Listening on 0.0.0.0:2727 == Using TOS bits 0 == Registered channel type 'MGCP' (Media Gateway Control Protocol (MGCP)) [chan_sip.so] => (Session Initiation Protocol (SIP)) == Parsing '/etc/asterisk/sip.conf': Found -- SIP Seeding peer from astdb: '747' at 747@192.168.6.215:5060 for 3600 Jun 22 23:02:31 DEBUG[30900]: db.c:197 ast_db_get: Unable to find key '7067' in family 'SIP/Registry' -- SIP Seeding peer from astdb: '7066' at 7066@192.168.0.12:54990 for 3600 -- SIP Seeding peer from astdb: '706' at 706@192.168.0.200:5060 for 3600 -- SIP Seeding peer from astdb: '711' at 711@192.168.6.252:5060 for 3600 -- SIP Seeding peer from astdb: '731' at 731@192.168.6.156:5060 for 3600 == SIP Listening on 0.0.0.0:5060 == Using SIP TOS: none == Parsing '/etc/asterisk/sip_notify.conf': Found == Registered channel type 'SIP' (Session Initiation Protocol (SIP)) == Registered application 'SIPDtmfMode' == Registered application 'SIPAddHeader' == Registered custom function SIP_HEADER == Registered custom function SIPPEER == Registered custom function SIPCHANINFO == Registered custom function CHECKSIPDOMAIN == Manager registered action SIPpeers == Manager registered action SIPshowpeer [chan_jingle.so] => (Jingle Channel) == Parsing '/etc/asterisk/jingle.conf': Found == Registered channel type 'Jingle' (Jingle Channel Driver) [chan_oss.so] => (OSS Console Channel Driver) == Parsing '/etc/asterisk/oss.conf': Found == Registered channel type 'Console' (OSS Console Channel Driver) [chan_iax2.so] => (Inter Asterisk eXchange (Ver 2)) == Registered custom function IAXPEER == Registered application 'IAX2Provision' == Manager registered action IAXpeers == Manager registered action IAXnetstats == Parsing '/etc/asterisk/iax.conf': Found == Using TOS bits 0 == Binding IAX2 to default address 0.0.0.0:4569 > doing dnsmgr_lookup for '216.207.245.47' == Registered channel type 'IAX2' (Inter Asterisk eXchange Driver (Ver 2)) == 10 helper threaads started == IAX Ready and Listening == Loaded firmware 'iaxy.bin' == Parsing '/etc/asterisk/iaxprov.conf': Found -- Loaded provisioning template 'default' [skipping chan_alsa.so] [app_record.so] => (Trivial Record Application) == Registered application 'Record' [app_getcpeid.so] => (Get ADSI CPE ID) == Registered application 'GetCPEID' [app_realtime.so] => (Realtime Data Lookup/Rewrite) == Registered application 'RealTimeUpdate' == Registered application 'RealTime' [app_sendtext.so] => (Send Text Applications) == Registered application 'SendText' [format_g726.so] => (Raw G.726 (16/24/32/40kbps) data) == Registered file format g726-40, extension(s) g726-40 == Registered file format g726-32, extension(s) g726-32 == Registered file format g726-24, extension(s) g726-24 == Registered file format g726-16, extension(s) g726-16 [func_math.so] => (Mathematical dialplan function) == Registered custom function MATH [app_directory.so] => (Extension Directory) == Registered application 'Directory' [app_privacy.so] => (Require phone number to be entered, if no CallerID sent) == Registered application 'PrivacyManager' [format_g729.so] => (Raw G729 data) == Registered file format g729, extension(s) g729 [app_externalivr.so] => (External IVR Interface Application) == Registered application 'ExternalIVR' [format_h264.so] => (Raw h264 data) == Registered file format h264, extension(s) h264 [app_mp3.so] => (Silly MP3 Application) == Registered application 'MP3Player' [app_system.so] => (Generic System() application) == Registered application 'TrySystem' == Registered application 'System' [func_base64.so] => (base64 encode/decode dialplan functions) == Registered custom function BASE64_ENCODE == Registered custom function BASE64_DECODE [app_setcallerid.so] => (Set CallerID Application) == Registered application 'SetCallerPres' == Registered application 'SetCallerID' [func_cdr.so] => (CDR dialplan function) == Registered custom function CDR [codec_g726.so] => (ITU G.726-32kbps G726 Transcoder) == Parsing '/etc/asterisk/codecs.conf': Found -- codec_g726: using generic PLC == Registered translator 'g726tolin' from format g726 to slin, cost 1 == Registered translator 'lintog726' from format slin to g726, cost 1 [app_while.so] => (While Loops and Conditional Execution) == Registered application 'While' == Registered application 'EndWhile' == Registered application 'ExitWhile' == Registered application 'ContinueWhile' [app_morsecode.so] => (Morse code) == Registered application 'Morsecode' [app_controlplayback.so] => (Control Playback Application) == Registered application 'ControlPlayback' [app_festival.so] => (Simple Festival Interface) == Registered application 'Festival' [func_language.so] => (Channel language dialplan function) == Registered custom function LANGUAGE [app_image.so] => (Image Transmission Application) == Registered application 'SendImage' [app_waitforsilence.so] => (Wait For Silence) == Registered application 'WaitForSilence' [func_odbc.so] => (ODBC lookups) == Parsing '/etc/asterisk/func_odbc.conf': Found == Registered custom function ODBC_SQL == Registered custom function ODBC_GETUSER == Registered custom function ODBC_CREATEACTIVECALL == Registered custom function ODBC_GETQUEUE == Registered custom function ODBC_ISVALIDREF == Registered custom function SQL_ESC [format_gsm.so] => (Raw GSM data) == Registered file format gsm, extension(s) gsm [app_authenticate.so] => (Authentication Application) == Registered application 'Authenticate' [app_nbscat.so] => (Silly NBS Stream Application) == Registered application 'NBScat' [app_talkdetect.so] => (Playback with Talk Detection) == Registered application 'BackgroundDetect' [app_sayunixtime.so] => (Say time) == Registered application 'SayUnixTime' == Registered application 'DateTime' [format_ogg_vorbis.so] => (OGG/Vorbis audio) == Registered file format ogg_vorbis, extension(s) ogg [app_mixmonitor.so] => (Mixed Audio Monitoring Application) == Registered application 'MixMonitor' == Registered application 'StopMixMonitor' [app_read.so] => (Read Variable Application) == Registered application 'Read' [codec_adpcm.so] => (Adaptive Differential PCM Coder/Decoder) == Parsing '/etc/asterisk/codecs.conf': Found -- codec_adpcm: using generic PLC == Registered translator 'adpcmtolin' from format adpcm to slin, cost 1 == Registered translator 'lintoadpcm' from format slin to adpcm, cost 1 [app_url.so] => (Send URL Applications) == Registered application 'SendURL' [app_dial.so] => (Dialing Application) == Registered application 'Dial' == Registered application 'RetryDial' [format_vox.so] => (Dialogic VOX (ADPCM) File Format) == Registered file format vox, extension(s) vox [func_moh.so] => (Music-on-hold dialplan function) == Registered custom function MUSICCLASS [app_voicemail.so] => (Comedian Mail (Voicemail System)) == Registered application 'VoiceMail' == Registered application 'VoiceMailMain' == Registered application 'MailboxExists' == Registered application 'VMAuthenticate' == Parsing '/etc/asterisk/voicemail.conf': Found Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6361 load_config: VM Review Option disabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6368 load_config: VM Temperary Greeting Reminder Option disabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6376 load_config: VM Operator break disabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6382 load_config: VM CID Info before msg disabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6388 load_config: Send Voicemail msg disabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6394 load_config: ENVELOPE before msg enabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6400 load_config: Duration info before msg enabled globally Jun 22 23:02:32 DEBUG[30900]: app_voicemail.c:6415 load_config: We are not going to skip to the next msg after save/delete Jun 22 23:02:32 WARNING[30900]: app_voicemail.c:6470 load_config: Invalid timezone definition at line 178 [app_dictate.so] => (Virtual Dictation Machine) == Registered application 'Dictate' [app_flash.so] => (Flash zap trunk application) == Registered application 'Flash' [app_milliwatt.so] => (Digital Milliwatt (mu-law) Test Application) == Registered application 'Milliwatt' [app_db.so] => (Database Access Functions) == Registered application 'DBdel' == Registered application 'DBdeltree' [func_rand.so] => (Random number dialplan function) == Registered custom function RAND [cdr_manager.so] => (Asterisk Call Manager CDR Backend) == Parsing '/etc/asterisk/cdr_manager.conf': Found [func_db.so] => (Database (astdb) related dialplan functions) == Registered custom function DB == Registered custom function DB_EXISTS == Registered custom function DB_DELETE [app_readfile.so] => (Stores output of file into a variable) == Registered application 'ReadFile' [func_enum.so] => (ENUM related dialplan functions) == Registered custom function ENUMLOOKUP == Registered custom function TXTCIDNAME [app_verbose.so] => (Send verbose output) == Registered application 'Log' == Registered application 'Verbose' [app_channelredirect.so] => (Channel Redirect) == Registered application 'ChannelRedirect' [format_g723.so] => (G.723.1 Simple Timestamp File Format) == Registered file format g723sf, extension(s) g723|g723sf [app_lookupcidname.so] => (Look up CallerID Name from local database) == Registered application 'LookupCIDName' [app_setcdruserfield.so] => (CDR user field apps) == Registered application 'SetCDRUserField' == Registered application 'AppendCDRUserField' == Manager registered action SetCDRUserField [format_wav.so] => (Microsoft WAV format (8000hz Signed Linear)) == Registered file format wav, extension(s) wav [func_realtime.so] => (Read/Write values from a RealTime repository) == Registered custom function REALTIME [app_amd.so] => (Answering Machine Detection Application) == Parsing '/etc/asterisk/amd.conf': Found -- AMD defaults: initialSilence [2500] greeting [1500] afterGreetingSilence [800] totalAnalysisTime [5000] minimumWordLength [100] betweenWordsSilence [50] maximumNumberOfWords [3] silenceThreshold [256] == Registered application 'AMD' [app_cdr.so] => (Tell Asterisk to not maintain a CDR for the current call) == Registered application 'NoCDR' [func_timeout.so] => (Channel timeout dialplan functions) == Registered custom function TIMEOUT [app_hasnewvoicemail.so] => (Indicator for whether a voice mailbox has messages in a given folder. == Registered custom function VMCOUNT == Registered application 'HasVoicemail' == Registered application 'HasNewVoicemail' [format_sln.so] => (Raw Signed Linear Audio support (SLN)) == Registered file format sln, extension(s) sln|raw [app_lookupblacklist.so] => (Look up Caller*ID name/number from blacklist database) == Registered custom function BLACKLIST == Registered application 'LookupBlacklist' [func_strings.so] => (String handling dialplan functions) == Registered custom function FIELDQTY == Registered custom function FILTER == Registered custom function REGEX == Registered custom function ARRAY == Registered custom function QUOTE == Registered custom function LEN == Registered custom function STRFTIME == Registered custom function STRPTIME == Registered custom function EVAL == Registered custom function KEYPADHASH == Registered custom function SPRINTF [app_ices.so] => (Encode and Stream via icecast and ices) == Registered application 'ICES' [app_disa.so] => (DISA (Direct Inward System Access) Application) == Registered application 'DISA' [app_queue.so] => (True Call Queueing) == Registered application 'Queue' == Manager registered action Queues == Manager registered action QueueStatus == Manager registered action QueueAdd == Manager registered action QueueRemove == Manager registered action QueuePause == Registered application 'AddQueueMember' == Registered application 'RemoveQueueMember' == Registered application 'PauseQueueMember' == Registered application 'UnpauseQueueMember' == Registered custom function QUEUEAGENTCOUNT == Registered custom function QUEUE_MEMBER_COUNT == Registered custom function QUEUE_MEMBER_LIST == Registered custom function QUEUE_WAITING_COUNT == Parsing '/etc/asterisk/queues.conf': Found Jun 22 23:02:32 NOTICE[30900]: app_queue.c:2925 reload_queue_members: Queue members successfully reloaded from database. [format_h263.so] => (Raw h263 data) == Registered file format h263, extension(s) h263 [func_md5.so] => (MD5 digest dialplan functions) == Registered custom function MD5 == Registered custom function CHECK_MD5 [func_sha1.so] => (SHA-1 computation dialplan function) == Registered custom function SHA1 [codec_gsm.so] => (GSM/PCM16 (signed linear) Codec Translator) == Parsing '/etc/asterisk/codecs.conf': Found -- codec_gsm: using generic PLC == Registered translator 'gsmtolin' from format gsm to slin, cost 1 == Registered translator 'lintogsm' from format slin to gsm, cost 1 [func_cut.so] => (Cut out information from a string) == Registered custom function CUT == Registered custom function SORT [cdr_odbc.so] => (ODBC CDR Backend) Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:257 odbc_load_module: cdr_odbc: starting odbc load == Parsing '/etc/asterisk/cdr_odbc.conf': Found Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:266 odbc_load_module: cdr_odbc: #1 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:273 odbc_load_module: cdr_odbc: #2 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:279 odbc_load_module: cdr_odbc: #3 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:287 odbc_load_module: cdr_odbc: #4 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:295 odbc_load_module: cdr_odbc: #5 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:306 odbc_load_module: cdr_odbc: #6 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:317 odbc_load_module: cdr_odbc: #7 Jun 22 23:02:32 DEBUG[30900]: cdr_odbc.c:322 odbc_load_module: cdr_odbc: Logging uniqueid Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:331 odbc_load_module: cdr_odbc: #8 Jun 22 23:02:32 DEBUG[30900]: cdr_odbc.c:336 odbc_load_module: cdr_odbc: Logging in GMT Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:345 odbc_load_module: cdr_odbc: #9 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:358 odbc_load_module: cdr_odbc: #10 -- cdr_odbc: dsn is debtnet -- cdr_odbc: username is sysprogress -- cdr_odbc: password is [secret] -- cdr_odbc: table is PUB.cdr Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:374 odbc_load_module: cdr_odbc: #11 Jun 22 23:02:32 NOTICE[30900]: cdr_odbc.c:383 odbc_load_module: cdr_odbc: #12 [func_channel.so] => (Channel information dialplan function) == Registered custom function CHANNEL [func_global.so] => (Global variable dialplan functions) == Registered custom function GLOBAL [app_forkcdr.so] => (Fork The CDR into 2 separate entities.) == Registered application 'ForkCDR' [format_pcm.so] => (Raw/Sun uLaw/ALaw 8khz Audio support (PCM,PCMA,AU)) == Registered file format pcm, extension(s) pcm|ulaw|ul|mu == Registered file format alaw, extension(s) alaw|al == Registered file format au, extension(s) au [func_env.so] => (Environment/filesystem dialplan functions) == Registered custom function ENV == Registered custom function STAT [func_uri.so] => (URI encode/decode dialplan functions) == Registered custom function URIDECODE == Registered custom function URIENCODE [codec_ulaw.so] => (Mu-law Coder/Decoder) == Parsing '/etc/asterisk/codecs.conf': Found -- codec_ulaw: using generic PLC == Registered translator 'ulawtolin' from format ulaw to slin, cost 1 == Registered translator 'lintoulaw' from format slin to ulaw, cost 1 [app_settransfercapability.so] => (Set ISDN Transfer Capability) == Registered application 'SetTransferCapability' [cdr_csv.so] => (Comma Separated Values CDR Backend) == Parsing '/etc/asterisk/cdr.conf': Found Jun 22 23:02:33 DEBUG[30900]: cdr_csv.c:126 load_config: logging time in GMT Jun 22 23:02:33 DEBUG[30900]: cdr_csv.c:134 load_config: logging CDR field UNIQUEID Jun 22 23:02:33 DEBUG[30900]: cdr_csv.c:142 load_config: logging CDR user-defined field [codec_ilbc.so] => (iLBC/PCM16 (signed linear) Codec Translator) == Primary D-Channel on span 1 up == Registered translator 'ilbctolin' from format ilbc to slin, cost 2 == Registered translator 'lintoilbc' from format slin to ilbc, cost 13 [app_parkandannounce.so] => (Call Parking and Announce Application) == Registered application 'ParkAndAnnounce' [codec_lpc10.so] => (LPC10 2.4kbps (signed linear) Voice Coder) == Parsing '/etc/asterisk/codecs.conf': Found -- codec_lpc10: using generic PLC == Registered translator 'lpc10tolin' from format lpc10 to slin, cost 2 == Registered translator 'lintolpc10' from format slin to lpc10, cost 3 [codec_a_mu.so] => (A-law and Mulaw direct Coder/Decoder) == Registered translator 'alawtoulaw' from format alaw to ulaw, cost 1 == Registered translator 'ulawtoalaw' from format ulaw to alaw, cost 1 [app_dumpchan.so] => (Dump Info About The Calling Channel) == Registered application 'DumpChan' [cdr_pgsql.so] => (PostgreSQL CDR Backend) == Parsing '/etc/asterisk/cdr_pgsql.conf': Found == Primary D-Channel on span 1 up [app_random.so] => (Random goto) == Registered application 'Random' [app_transfer.so] => (Transfer) == Registered application 'Transfer' [format_ilbc.so] => (Raw iLBC data) == Registered file format iLBC, extension(s) ilbc [app_chanisavail.so] => (Check channel availability) == Registered application 'ChanIsAvail' [app_zapras.so] => (Zap RAS Application) == Registered application 'ZapRAS' [app_speech_utils.so] => (Dialplan Speech Applications) == Registered application 'SpeechCreate' == Registered application 'SpeechLoadGrammar' == Registered application 'SpeechUnloadGrammar' == Registered application 'SpeechActivateGrammar' == Registered application 'SpeechDeactivateGrammar' == Registered application 'SpeechStart' == Registered application 'SpeechBackground' == Registered application 'SpeechDestroy' == Registered application 'SpeechProcessingSound' == Registered custom function SPEECH == Registered custom function SPEECH_SCORE == Registered custom function SPEECH_TEXT == Registered custom function SPEECH_GRAMMAR [func_groupcount.so] => (Channel group dialplan functions) == Registered custom function GROUP_COUNT == Registered custom function GROUP_MATCH_COUNT == Registered custom function GROUP_LIST == Registered custom function GROUP [format_jpeg.so] => (JPEG (Joint Picture Experts Group) Image Format) == Registered format 'jpg' (JPEG (Joint Picture Experts Group)) [app_page.so] => (Page Multiple Phones) == Registered application 'Page' [app_alarmreceiver.so] => (Alarm Receiver for Asterisk) == Parsing '/etc/asterisk/alarmreceiver.conf': Found == Registered application 'AlarmReceiver' [app_adsiprog.so] => (Asterisk ADSI Programming Application) == Registered application 'ADSIProg' [app_exec.so] => (Executes dialplan applications) == Registered application 'Exec' == Registered application 'TryExec' == Registered application 'ExecIf' [codec_alaw.so] => (A-law Coder/Decoder) == Parsing '/etc/asterisk/codecs.conf': Found -- codec_alaw: using generic PLC == Registered translator 'alawtolin' from format alaw to slin, cost 1 == Registered translator 'lintoalaw' from format slin to alaw, cost 1 [app_followme.so] => (Find-Me/Follow-Me Application) Jun 22 23:02:33 WARNING[30900]: app_followme.c:298 reload_followme: No follow me config file (followme.conf), so no follow me == Registered application 'FollowMe' [format_wav_gsm.so] => (Microsoft WAV format (Proprietary GSM)) == Registered file format wav49, extension(s) WAV|wav49 [app_userevent.so] => (Custom User Event Application) == Registered application 'UserEvent' [cdr_custom.so] => (Customizable Comma Separated Values CDR Backend) == Parsing '/etc/asterisk/cdr_custom.conf': Found [app_meetme.so] => (MeetMe conference bridge) == Parsing '/etc/asterisk/meetme.conf': Found == Manager registered action MeetmeMute == Manager registered action MeetmeUnmute == Registered application 'MeetMeAdmin' == Registered application 'MeetMeCount' == Registered application 'MeetMe' [func_callerid.so] => (Caller ID related dialplan function) == Registered custom function CALLERID [app_senddtmf.so] => (Send DTMF digits Application) == Manager registered action PlayDTMF == Registered application 'SendDTMF' [app_directed_pickup.so] => (Directed Call Pickup Application) == Registered application 'Pickup' [app_zapbarge.so] => (Barge in on Zap channel application) == Registered application 'ZapBarge' [app_chanspy.so] => (Listen to the audio of an active channel) == Registered application 'ChanSpy' [app_zapscan.so] => (Scan Zap channels application) == Registered application 'ZapScan' [app_playback.so] => (Sound File Playback Application) == Parsing '/etc/asterisk/say.conf': Found == Registered application 'Playback' [app_macro.so] => (Extension Macros) == Registered application 'MacroExit' == Registered application 'MacroIf' == Registered application 'Macro' [func_logic.so] => (Logical dialplan functions) == Registered custom function ISNULL == Registered custom function SET == Registered custom function EXISTS == Registered custom function IF == Registered custom function IFTIME [app_zapateller.so] => (Block Telemarketers with Special Information Tone) == Registered application 'Zapateller' [app_test.so] => (Interface Test Application) == Registered application 'TestClient' == Registered application 'TestServer' [app_echo.so] => (Simple Echo Application) == Registered application 'Echo' [skipping chan_alsa.so] [func_curl.so] => (Load external URL) == Registered custom function CURL [app_stack.so] => (Stack Routines) == Registered application 'StackPop' == Registered application 'Return' == Registered application 'GosubIf' == Registered application 'Gosub' [app_sms.so] => (SMS/PSTN handler) == Registered application 'SMS' [app_waitforring.so] => (Waits until first ring after time) == Registered application 'WaitForRing' [app_softhangup.so] => (Hangs up the requested channel) == Registered application 'SoftHangup' Jun 22 23:02:33 DEBUG[30900]: loader.c:389 fixup: ---- fixup (load_modules): 153 modules, 0 new --- Jun 22 23:02:33 DEBUG[30900]: loader.c:394 fixup: ---- fixup: cycle 0 --- Jun 22 23:02:33 DEBUG[30900]: loader.c:425 fixup: ---- fixup complete --- == Manager registered action DBGet == Manager registered action DBPut == Parsing '/etc/asterisk/enum.conf': Found Asterisk Ready. *CLI> debug 4 No such command 'debug 4' (type 'help' for help) *CLI> set debug 4 Core debug was 0 and is now 4 *CLI> sip debug SIP Debugging enabled *CLI> <-- SIP read from 192.168.0.12:54990: INVITE sip:706@foxtrot.tessera.co.uk SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-426e691b565fa71c-1--d87543-;rport Max-Forwards: 70 Contact: To: "706" From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 381 v=0 o=- 9 2 IN IP4 192.168.0.12 s= c=IN IP4 192.168.0.12 t=0 0 m=audio 13484 RTP/AVP 107 119 0 98 8 3 101 a=alt:1 1 : bTMQh0Bt 8MuYK+Td 192.168.0.12 13484 a=fmtp:101 0-15 a=rtpmap:107 BV32/16000 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:706@foxtrot.tessera.co.uk SIP/2.0 (44) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-426e691b565fa71c-1--d87543-;rport (91) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706" (40) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 1 INVITE (14) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: Content-Length: 381 (19) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=- 9 2 IN IP4 192.168.0.12 (27) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s= (27) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.0.12 (21) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 13484 RTP/AVP 107 119 0 98 8 3 101 (42) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=alt:1 1 : bTMQh0Bt 8MuYK+Td 192.168.0.12 13484 (48) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:107 BV32/16000 (23) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:119 BV32-FEC/16000 (27) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:98 iLBC/8000 (21) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 (51) --- (12 headers 14 lines)--- Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4087 sip_alloc: Allocating new SIP dialog for 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. - INVITE (With RTP) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.12 : 54990 (NAT) Using INVITE request as basis request - 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:8608 check_user_full: Setting NAT on RTP to Off Reliably Transmitting (no NAT) to 192.168.0.12:54990: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-426e691b565fa71c-1--d87543-;rport;received=192.168.0.12 From: "Foxtrot";tag=1221994f To: "706";tag=as0c1f6ba9 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="746ea9c7" Content-Length: 0 --- Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #15 Scheduling destruction of SIP dialog '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' in 32000 ms (Method: INVITE) Found user '7066' <-- SIP read from 192.168.0.12:54990: ACK sip:706@foxtrot.tessera.co.uk SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-426e691b565fa71c-1--d87543-;rport To: "706";tag=as0c1f6ba9 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 1 ACK Content-Length: 0 Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@foxtrot.tessera.co.uk SIP/2.0 (41) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-426e691b565fa71c-1--d87543-;rport (91) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: To: "706";tag=as0c1f6ba9 (55) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: From: "Foxtrot";tag=1221994f (60) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: CSeq: 1 ACK (11) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Content-Length: 0 (17) Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: (0) --- (7 headers 0 lines)--- Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #15 Jun 22 23:02:57 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' of Response 1: Match Not Found <-- SIP read from 192.168.0.12:54990: INVITE sip:706@foxtrot.tessera.co.uk SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-ee07a968ba00a000-1--d87543-;rport Max-Forwards: 70 Contact: To: "706" From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@foxtrot.tessera.co.uk",response="2fa552d371435a286da12a77dcb4dcb8",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 381 v=0 o=- 9 2 IN IP4 192.168.0.12 s= c=IN IP4 192.168.0.12 t=0 0 m=audio 13484 RTP/AVP 107 119 0 98 8 3 101 a=alt:1 1 : bTMQh0Bt 8MuYK+Td 192.168.0.12 13484 a=fmtp:101 0-15 a=rtpmap:107 BV32/16000 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:706@foxtrot.tessera.co.uk SIP/2.0 (44) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-ee07a968ba00a000-1--d87543-;rport (91) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706" (40) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 2 INVITE (14) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@foxtrot.tessera.co.uk",response="2fa552d371435a286da12a77dcb4dcb8",algorithm=MD5 (171) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: Content-Length: 381 (19) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=- 9 2 IN IP4 192.168.0.12 (27) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s= (27) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.0.12 (21) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 13484 RTP/AVP 107 119 0 98 8 3 101 (42) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=alt:1 1 : bTMQh0Bt 8MuYK+Td 192.168.0.12 13484 (48) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:107 BV32/16000 (23) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:119 BV32-FEC/16000 (27) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:98 iLBC/8000 (21) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 (51) --- (13 headers 14 lines)--- Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.12 : 54990 (NAT) Using INVITE request as basis request - 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:8608 check_user_full: Setting NAT on RTP to Off Found user '7066' Found RTP audio format 107 Found RTP audio format 119 Found RTP audio format 0 Found RTP audio format 98 Found RTP audio format 8 Found RTP audio format 3 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.12:13484 Got unsupported a:fmtp in SDP offer Found description format BV32 for ID 107 Found description format BV32-FEC for ID 119 Found description format iLBC for ID 98 Found description format telephone-event for ID 101 Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.0.12:13484 Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:12782 handle_request_invite: Checking SIP call limits for device 7066 Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:2841 update_call_counter: Updating call counter for incoming call Looking for 706 in from-sip (domain foxtrot.tessera.co.uk) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:3576 sip_new: *** Our native formats are 0x4 (ulaw) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:3577 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:3578 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:3579 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:3602 sip_new: This channel will not be able to handle video. Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:7571 build_route: build_route: Contact hop: list_route: hop: Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:12852 handle_request_invite: SIP/7066-36f1: New call is still down.... Trying... Transmitting (no NAT) to 192.168.0.12:54990: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-ee07a968ba00a000-1--d87543-;rport;received=192.168.0.12 From: "Foxtrot";tag=1221994f To: "706" Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 22 23:02:58 DEBUG[30904]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 7066 Jun 22 23:02:58 DEBUG[30904]: devicestate.c:189 do_state_change: Changing state for SIP/7066 - state 1 (Not in use) Jun 22 23:02:58 DEBUG[30931]: pbx.c:1675 pbx_extension_helper: Launching 'Answer' -- Executing [706@from-sip:1] Answer("SIP/7066-36f1", "") in new stack Jun 22 23:02:58 DEBUG[30904]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 7066 Jun 22 23:02:58 DEBUG[30904]: devicestate.c:189 do_state_change: Changing state for SIP/7066 - state 1 (Not in use) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3282 sip_answer: SIP answering channel: SIP/7066-36f1 Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 90.0.0.62 port 19106 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-ee07a968ba00a000-1--d87543-;rport;received=192.168.0.12 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30900 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #17 Jun 22 23:02:58 DEBUG[30931]: pbx.c:1675 pbx_extension_helper: Launching 'Dial' -- Executing [706@from-sip:2] Dial("SIP/7066-36f1", "SIP/706") in new stack Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:14588 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4087 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:2476 create_addr_from_peer: Setting NAT on RTP to Off Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3576 sip_new: *** Our native formats are 0x4 (ulaw) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3577 sip_new: *** Joint capabilities are 0x0 (nothing) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3578 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3579 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3581 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:3602 sip_new: This channel will not be able to handle video. Jun 22 23:02:58 DEBUG[30931]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-from-sip-706-2. Jun 22 23:02:58 DEBUG[30931]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-from-sip-706-1. Jun 22 23:02:58 DEBUG[30931]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPCALLID. Jun 22 23:02:58 DEBUG[30931]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Jun 22 23:02:58 DEBUG[30931]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Jun 22 23:02:58 DEBUG[30931]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPURI. Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:2678 sip_call: Outgoing Call for 706 Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:2686 sip_call: Our T38 capability (0), joint T38 capability (0) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 90.0.0.62 port 13468 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:706@192.168.0.200:5060 SIP/2.0 (41) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport (60) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 2: From: "xlite" ;tag=as26722de4 (49) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 3: To: (32) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 4: Contact: (29) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 5: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 8: Max-Forwards: 70 (16) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 9: Date: Thu, 22 Jun 2006 22:02:58 GMT (35) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 11: Supported: replaces (19) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 12: Content-Type: application/sdp (29) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 13: Content-Length: 269 (19) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4307 parse_request: Header 14: (0) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: o=root 30900 30900 IN IP4 90.0.0.62 (35) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: s=session (9) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: c=IN IP4 90.0.0.62 (18) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: m=audio 13468 RTP/AVP 0 8 3 101 (31) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-16 (15) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=silenceSupp:off - - - - (25) Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 192.168.0.200:5060: INVITE sip:706@192.168.0.200:5060 SIP/2.0 Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport From: "xlite" ;tag=as26722de4 To: Contact: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Thu, 22 Jun 2006 22:02:58 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30900 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 13468 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 22 23:02:58 DEBUG[30932]: app_queue.c:529 changethread: Device 'SIP/7066' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 22 23:02:58 DEBUG[30933]: app_queue.c:529 changethread: Device 'SIP/7066' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 22 23:02:58 DEBUG[30931]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18 -- Called 706 Jun 22 23:02:58 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to read format ulaw Jun 22 23:02:58 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:02:58 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to read format ulaw Jun 22 23:02:58 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to write format ulaw Jun 22 23:02:58 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 132 bytes <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-c36ff1607536e23d-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 2 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@foxtrot.tessera.co.uk",response="2fa552d371435a286da12a77dcb4dcb8",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-c36ff1607536e23d-1--d87543-;rport (91) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 2 ACK (11) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@foxtrot.tessera.co.uk",response="2fa552d371435a286da12a77dcb4dcb8",algorithm=MD5 (171) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #17 Jun 22 23:02:58 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' of Response 2: Match Not Found <-- SIP read from 192.168.0.200:52829: SIP/2.0 100 Trying Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport From: "xlite" ;tag=as26722de4 To: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:02:58 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 100 Trying (18) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport (60) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: "xlite" ;tag=as26722de4 (49) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: (32) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:02:58 GMT (35) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Length: 0 (17) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:2017 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #18 - INVITE (got response) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:2026 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' Request 102: Found Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:11140 handle_response_invite: SIP response 100 to standard invite <-- SIP read from 192.168.0.200:52830: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport From: "xlite" ;tag=as26722de4 To: ;tag=000785993d3d05b0143670ee-2a075828 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:02:58 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport (60) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: "xlite" ;tag=as26722de4 (49) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=000785993d3d05b0143670ee-2a075828 (70) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:02:58 GMT (35) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Length: 0 (17) Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:2026 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' Request 102: Found Jun 22 23:02:59 DEBUG[30916]: chan_sip.c:11140 handle_response_invite: SIP response 180 to standard invite -- SIP/706-2ba0 is ringing Jun 22 23:02:59 DEBUG[30931]: channel.c:2172 ast_indicate_data: Driver for channel 'SIP/7066-36f1' does not support indication 3, emulating it Jun 22 23:02:59 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format slin Jun 22 23:02:59 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 22 23:02:59 DEBUG[30904]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 706 Jun 22 23:02:59 DEBUG[30904]: devicestate.c:189 do_state_change: Changing state for SIP/706 - state 1 (Not in use) Jun 22 23:02:59 DEBUG[30934]: app_queue.c:529 changethread: Device 'SIP/706' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 22 23:02:59 DEBUG[30931]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 22 23:02:59 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:02:59 DEBUG[30931]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw Jun 22 23:03:01 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes Jun 22 23:03:04 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.200:52831: SIP/2.0 200 OK Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport From: "xlite" ;tag=as26722de4 To: ;tag=000785993d3d05b0143670ee-2a075828 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:03 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 199 v=0 o=Cisco-SIPUA 23454 27754 IN IP4 192.168.0.200 s=SIP Call c=IN IP4 192.168.0.200 t=0 0 m=audio 27976 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2140feb6;rport (60) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: "xlite" ;tag=as26722de4 (49) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=000785993d3d05b0143670ee-2a075828 (70) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:03 GMT (35) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 199 (19) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=Cisco-SIPUA 23454 27754 IN IP4 192.168.0.200 (46) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s=SIP Call (10) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.0.200 (22) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 27976 RTP/AVP 0 101 (27) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines)--- Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:1966 __sip_ack: Acked pending invite 102 Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' of Request 102: Match Not Found Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:11140 handle_response_invite: SIP response 200 to standard invite Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.200:27976 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/706-2ba0 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.0.200:27976 Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:7571 build_route: build_route: Contact hop: list_route: hop: Jun 22 23:03:04 DEBUG[30916]: chan_sip.c:5318 reqprep: Strict routing enforced for session 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.200, port 5060 Transmitting (no NAT) to 192.168.0.200:5060: ACK sip:706@192.168.0.200:5060 SIP/2.0 Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK4da0fd82;rport From: "xlite" ;tag=as26722de4 To: ;tag=000785993d3d05b0143670ee-2a075828 Contact: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/706-2ba0 answered SIP/7066-36f1 Jun 22 23:03:04 DEBUG[30904]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 706 Jun 22 23:03:04 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:03:04 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:04 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to read format ulaw Jun 22 23:03:04 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to write format ulaw Jun 22 23:03:04 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to read format ulaw Jun 22 23:03:04 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:03:04 DEBUG[30904]: devicestate.c:189 do_state_change: Changing state for SIP/706 - state 1 (Not in use) Jun 22 23:03:04 DEBUG[30935]: app_queue.c:529 changethread: Device 'SIP/706' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 22 23:03:04 DEBUG[30931]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.0.12:54990: Jun 22 23:03:06 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: (0) Jun 22 23:03:06 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: (0) --- (0 headers 1 lines)--- Jun 22 23:03:07 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes Jun 22 23:03:10 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.200:52832: INVITE sip:7066@90.0.0.62:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK782ea29e From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:10 GMT CSeq: 101 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 193 Remote-Party-ID: "706" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 21460 13142 IN IP4 192.168.0.200 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 27976 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:7066@90.0.0.62:5060 SIP/2.0 (38) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK782ea29e (58) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=000785993d3d05b0143670ee-2a075828 (72) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: "xlite" ;tag=as26722de4 (47) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:10 GMT (35) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 101 INVITE (16) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 193 (19) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: Remote-Party-ID: "706" ;party=calling;id-type=subscriber;privacy=off;screen=no (101) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=Cisco-SIPUA 21460 13142 IN IP4 192.168.0.200 (46) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s=SIP Call (10) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 27976 RTP/AVP 0 101 (27) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 9 lines)--- Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.200 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:27976 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/706-2ba0 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 0.0.0.0:27976 Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call -- Started music on hold, class 'default', on SIP/7066-36f1 Jun 22 23:03:11 DEBUG[30916]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:12919 handle_request_invite: SIP/706-2ba0: New call is UP.... Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 90.0.0.62 port 13468 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.0.200:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK782ea29e;received=192.168.0.200 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 13468 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #22 Jun 22 23:03:11 DEBUG[30931]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 22 23:03:11 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:11 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:03:11 DEBUG[30931]: res_musiconhold.c:251 ast_moh_files_next: SIP/7066-36f1 Opened file 11 '/var/lib/asterisk/sounds/custom/moh/track20' Jun 22 23:03:11 DEBUG[30931]: rtp.c:2240 ast_rtp_raw_write: Difference is 1000, ms is 145 <-- SIP read from 192.168.0.200:52833: ACK sip:7066@90.0.0.62:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK7a4b5514 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:10 GMT CSeq: 101 ACK User-Agent: CSCO/7 Content-Length: 0 Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:7066@90.0.0.62:5060 SIP/2.0 (35) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK7a4b5514 (58) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=000785993d3d05b0143670ee-2a075828 (72) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: "xlite" ;tag=as26722de4 (47) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:10 GMT (35) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 101 ACK (13) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 0 (17) Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #22 Jun 22 23:03:11 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' of Response 101: Match Not Found Jun 22 23:03:13 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes RTCP SR transmission error, rtcp halted No such file or directory Jun 22 23:03:14 NOTICE[30916]: sched.c:287 ast_sched_del: Attempted to delete nonexistent schedule entry 21! Jun 22 23:03:16 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes Jun 22 23:03:19 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.200:52834: INVITE sip:7066@90.0.0.62:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK7babe613 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:21 GMT CSeq: 102 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 247 Remote-Party-ID: "706" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 1559 1616 IN IP4 192.168.0.200 s=SIP Call c=IN IP4 192.168.0.200 t=0 0 m=audio 27976 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:7066@90.0.0.62:5060 SIP/2.0 (38) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK7babe613 (58) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=000785993d3d05b0143670ee-2a075828 (72) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: "xlite" ;tag=as26722de4 (47) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:21 GMT (35) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 247 (19) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: Remote-Party-ID: "706" ;party=calling;id-type=subscriber;privacy=off;screen=no (101) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=Cisco-SIPUA 1559 1616 IN IP4 192.168.0.200 (44) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s=SIP Call (10) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.0.200 (22) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 27976 RTP/AVP 0 8 18 101 (32) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 11 lines)--- Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.200 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.200:27976 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format G729 for ID 18 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/706-2ba0 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.0.200:27976 Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call -- Stopped music on hold on SIP/7066-36f1 Jun 22 23:03:22 DEBUG[30916]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:03:22 DEBUG[30916]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:12919 handle_request_invite: SIP/706-2ba0: New call is UP.... Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 90.0.0.62 port 13468 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.0.200:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK7babe613;received=192.168.0.200 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 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: 269 v=0 o=root 30900 30902 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 13468 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #23 <-- SIP read from 192.168.0.200:52835: ACK sip:7066@90.0.0.62:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK13c385b9 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:21 GMT CSeq: 102 ACK User-Agent: CSCO/7 Content-Length: 0 Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:7066@90.0.0.62:5060 SIP/2.0 (35) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK13c385b9 (58) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=000785993d3d05b0143670ee-2a075828 (72) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: "xlite" ;tag=as26722de4 (47) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:21 GMT (35) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 ACK (13) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 0 (17) Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #23 Jun 22 23:03:22 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' of Response 102: Match Not Found Jun 22 23:03:22 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes Jun 22 23:03:26 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.12:54990: INVITE sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 238 v=0 o=- 9 3 IN IP4 192.168.0.12 s= c=IN IP4 0.0.0.0 t=0 0 m=audio 13484 RTP/AVP 0 8 3 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendonly a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:706@90.0.0.62 SIP/2.0 (32) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;rport (91) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 INVITE (14) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: Content-Length: 238 (19) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=- 9 3 IN IP4 192.168.0.12 (27) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s= (27) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 13484 RTP/AVP 0 8 3 101 (31) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 (51) --- (13 headers 10 lines)--- Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.12 : 54990 (NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 3 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:13484 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/7066-36f1 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 0.0.0.0:13484 Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call -- Started music on hold, class 'default', on SIP/706-2ba0 Jun 22 23:03:28 DEBUG[30916]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:12919 handle_request_invite: SIP/7066-36f1: New call is UP.... Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 90.0.0.62 port 19106 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- Jun 22 23:03:28 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #25 Jun 22 23:03:28 DEBUG[30931]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 22 23:03:28 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:28 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to write format ulaw Jun 22 23:03:28 DEBUG[30931]: res_musiconhold.c:251 ast_moh_files_next: SIP/706-2ba0 Opened file 15 '/var/lib/asterisk/sounds/custom/moh/track04' Jun 22 23:03:28 DEBUG[30931]: rtp.c:2240 ast_rtp_raw_write: Difference is 3272, ms is 429 Jun 22 23:03:29 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.12:54990: INVITE sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 238 v=0 o=- 9 3 IN IP4 192.168.0.12 s= c=IN IP4 0.0.0.0 t=0 0 m=audio 13484 RTP/AVP 0 8 3 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendonly a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:706@90.0.0.62 SIP/2.0 (32) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;rport (91) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 INVITE (14) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: Content-Length: 238 (19) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=- 9 3 IN IP4 192.168.0.12 (27) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s= (27) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 13484 RTP/AVP 0 8 3 101 (31) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 (51) --- (13 headers 10 lines)--- Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:13984 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 3, ours 3) Ignoring this INVITE request Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:12832 handle_request_invite: Got a SIP re-transmit of INVITE for call 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:12919 handle_request_invite: SIP/7066-36f1: New call is UP.... Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 90.0.0.62 port 19106 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30902 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #26 <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #26 Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' of Response 3: Match Not Found Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:1776 retrans_pkt: SIP TIMER: Rescheduling retransmission #25 (1) SIP/2.0 - 1 Jun 22 23:03:29 DEBUG[30916]: chan_sip.c:1790 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #25)) Retransmitting #1 (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:1776 retrans_pkt: SIP TIMER: Rescheduling retransmission #25 (2) SIP/2.0 - 1 Jun 22 23:03:30 DEBUG[30916]: chan_sip.c:1790 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id #25)) Retransmitting #2 (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:31 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:31 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes Jun 22 23:03:32 DEBUG[30916]: chan_sip.c:1776 retrans_pkt: SIP TIMER: Rescheduling retransmission #25 (3) SIP/2.0 - 1 Jun 22 23:03:32 DEBUG[30916]: chan_sip.c:1790 retrans_pkt: ** SIP timers: Rescheduling retransmission 4 to 4000 ms (t1 500 ms (Retrans id #25)) Retransmitting #3 (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:33 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:34 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 156 bytes <-- SIP read from 192.168.0.12:54990: Jun 22 23:03:36 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: (0) Jun 22 23:03:36 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: (0) --- (0 headers 1 lines)--- Jun 22 23:03:36 DEBUG[30916]: chan_sip.c:1776 retrans_pkt: SIP TIMER: Rescheduling retransmission #25 (4) SIP/2.0 - 1 Jun 22 23:03:36 DEBUG[30916]: chan_sip.c:1790 retrans_pkt: ** SIP timers: Rescheduling retransmission 5 to 4000 ms (t1 500 ms (Retrans id #25)) Retransmitting #4 (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:37 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:37 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 156 bytes <-- SIP read from 192.168.0.12:54990: INVITE sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-31126645c21b302c-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 4 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 243 v=0 o=- 9 4 IN IP4 192.168.0.12 s= c=IN IP4 192.168.0.12 t=0 0 m=audio 13484 RTP/AVP 0 8 3 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:706@90.0.0.62 SIP/2.0 (32) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-31126645c21b302c-1--d87543-;rport (91) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 4 INVITE (14) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: Content-Length: 243 (19) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=- 9 4 IN IP4 192.168.0.12 (27) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s= (27) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.0.12 (21) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 13484 RTP/AVP 0 8 3 101 (31) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=x-rtp-session-id:4FCFA497886B400F95B606C026D9F0B4 (51) --- (13 headers 10 lines)--- Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.12 : 54990 (NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 3 Found RTP audio format 101 Peer audio RTP is at port 192.168.0.12:13484 Got unsupported a:fmtp in SDP offer Found description format telephone-event for ID 101 Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/7066-36f1 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 192.168.0.12:13484 Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call -- Stopped music on hold on SIP/706-2ba0 Jun 22 23:03:40 DEBUG[30916]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to write format ulaw Jun 22 23:03:40 DEBUG[30916]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:12919 handle_request_invite: SIP/7066-36f1: New call is UP.... Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 90.0.0.62 port 19106 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-31126645c21b302c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 4 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30903 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #27 <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5c4c5804be2f6530-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 4 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5c4c5804be2f6530-1--d87543-;rport (91) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 4 ACK (11) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #27 Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' of Response 4: Match Not Found Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:1776 retrans_pkt: SIP TIMER: Rescheduling retransmission #25 (5) SIP/2.0 - 1 Jun 22 23:03:40 DEBUG[30916]: chan_sip.c:1790 retrans_pkt: ** SIP timers: Rescheduling retransmission 6 to 4000 ms (t1 500 ms (Retrans id #25)) Retransmitting #5 (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- Jun 22 23:03:40 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:13969 handle_request: Ignoring too old SIP packet packet 3 (expecting >= 4) Jun 22 23:03:41 DEBUG[30916]: chan_sip.c:14177 sipsock_read: SIP message could not be handled, bad request: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:03:43 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes Jun 22 23:03:44 DEBUG[30916]: chan_sip.c:1776 retrans_pkt: SIP TIMER: Rescheduling retransmission #25 (6) SIP/2.0 - 1 Jun 22 23:03:44 DEBUG[30916]: chan_sip.c:1790 retrans_pkt: ** SIP timers: Rescheduling retransmission 7 to 4000 ms (t1 500 ms (Retrans id #25)) Retransmitting #6 (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-f365cb2a42318c0c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30901 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 19106 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- <-- SIP read from 192.168.0.12:54990: ACK sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 3 ACK Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Content-Length: 0 Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5172d60c346d371e-1--d87543-;rport (91) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 3 ACK (11) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="9fdaf4a1f625bf3243aa7790fdabd57c",algorithm=MD5 (159) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:13969 handle_request: Ignoring too old SIP packet packet 3 (expecting >= 4) Jun 22 23:03:45 DEBUG[30916]: chan_sip.c:14177 sipsock_read: SIP message could not be handled, bad request: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. Jun 22 23:03:45 DEBUG[30931]: chan_sip.c:3868 sip_rtp_read: Oooh, format changed to 2 Jun 22 23:03:45 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to read format ulaw Jun 22 23:03:45 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:03:45 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to read format slin Jun 22 23:03:45 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to write format slin Jun 22 23:03:45 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/706-2ba0 to read format slin Jun 22 23:03:45 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format slin Jun 22 23:03:45 DEBUG[30931]: rtp.c:2341 ast_rtp_write: Ooh, format changed from ulaw to gsm Jun 22 23:03:47 DEBUG[30931]: rtp.c:783 ast_rtcp_read: Got RTCP report of 176 bytes <-- SIP read from 192.168.0.200:52836: INVITE sip:7066@90.0.0.62:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK2dcb317b From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:47 GMT CSeq: 103 INVITE User-Agent: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 242 Remote-Party-ID: "706" ;party=calling;id-type=subscriber;privacy=off;screen=no v=0 o=Cisco-SIPUA 3731 12725 IN IP4 192.168.0.200 s=SIP Call c=IN IP4 0.0.0.0 t=0 0 m=audio 27976 RTP/AVP 0 8 18 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:7066@90.0.0.62:5060 SIP/2.0 (38) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK2dcb317b (58) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=000785993d3d05b0143670ee-2a075828 (72) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: "xlite" ;tag=as26722de4 (47) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:47 GMT (35) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 103 INVITE (16) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 242 (19) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: Remote-Party-ID: "706" ;party=calling;id-type=subscriber;privacy=off;screen=no (101) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: o=Cisco-SIPUA 3731 12725 IN IP4 192.168.0.200 (45) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: s=SIP Call (10) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: m=audio 27976 RTP/AVP 0 8 18 101 (32) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:18 G729/8000 (21) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) --- (12 headers 11 lines)--- Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.0.200 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:27976 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format G729 for ID 18 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/706-2ba0 Capabilities: us - 0xe (gsm|ulaw|alaw), peer - audio=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264)/video=0x3d07ff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|jpeg|h261|h263|h263p|h264), combined - 0xe (gsm|ulaw|alaw) Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Peer audio RTP is at port 0.0.0.0:27976 Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call -- Started music on hold, class 'default', on SIP/7066-36f1 Jun 22 23:03:48 DEBUG[30916]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:12919 handle_request_invite: SIP/706-2ba0: New call is UP.... Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 90.0.0.62 port 13468 Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.0.200:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK2dcb317b;received=192.168.0.200 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 CSeq: 103 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 269 v=0 o=root 30900 30903 IN IP4 90.0.0.62 s=session c=IN IP4 90.0.0.62 t=0 0 m=audio 13468 RTP/AVP 0 8 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=recvonly --- Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #29 Jun 22 23:03:48 DEBUG[30931]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 22 23:03:48 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:48 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format ulaw Jun 22 23:03:48 DEBUG[30931]: res_musiconhold.c:251 ast_moh_files_next: SIP/7066-36f1 Opened file 11 '/var/lib/asterisk/sounds/custom/moh/track20' Jun 22 23:03:48 DEBUG[30931]: rtp.c:2240 ast_rtp_raw_write: Difference is 66440, ms is 8325 <-- SIP read from 192.168.0.200:52837: ACK sip:7066@90.0.0.62:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK768196b5 From: ;tag=000785993d3d05b0143670ee-2a075828 To: "xlite" ;tag=as26722de4 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:48 GMT CSeq: 103 ACK User-Agent: CSCO/7 Content-Length: 0 Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: ACK sip:7066@90.0.0.62:5060 SIP/2.0 (35) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.200:5060;branch=z9hG4bK768196b5 (58) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=000785993d3d05b0143670ee-2a075828 (72) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: "xlite" ;tag=as26722de4 (47) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:48 GMT (35) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 103 ACK (13) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 0 (17) Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #29 Jun 22 23:03:48 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' of Response 103: Match Not Found Jun 22 23:03:48 WARNING[30916]: chan_sip.c:1809 retrans_pkt: Maximum retries exceeded on transmission 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. for seqno 3 (Critical Response) Jun 22 23:03:48 WARNING[30916]: chan_sip.c:1826 retrans_pkt: Hanging up call 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. - no reply to our critical packet. -- Stopped music on hold on SIP/7066-36f1 Jun 22 23:03:48 DEBUG[30931]: channel.c:2492 set_format: Set channel SIP/7066-36f1 to write format slin Jun 22 23:03:48 DEBUG[30931]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 22 23:03:48 DEBUG[30931]: channel.c:3398 ast_generic_bridge: Didn't get a frame from channel: SIP/7066-36f1 Jun 22 23:03:48 DEBUG[30931]: channel.c:3684 ast_channel_bridge: Bridge stops bridging channels SIP/7066-36f1 and SIP/706-2ba0 Jun 22 23:03:48 DEBUG[30931]: channel.c:1493 ast_hangup: Hanging up channel 'SIP/706-2ba0' Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:3141 sip_hangup: Hangup call SIP/706-2ba0, SIP callid 020de1d54ccecb9d2361709321e49ff6@90.0.0.62) Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:3149 sip_hangup: update_call_counter(706) - decrement call limit counter on hangup Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:5318 reqprep: Strict routing enforced for session 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.0.200, port 5060 Reliably Transmitting (no NAT) to 192.168.0.200:5060: BYE sip:706@192.168.0.200:5060 SIP/2.0 Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2d10adb2;rport From: "xlite" ;tag=as26722de4 To: ;tag=000785993d3d05b0143670ee-2a075828 Contact: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #30 Jun 22 23:03:48 DEBUG[30931]: rtp.c:1321 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything Jun 22 23:03:48 DEBUG[30931]: app_dial.c:1621 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jun 22 23:03:48 DEBUG[30931]: pbx.c:2258 __ast_pbx_run: Spawn extension (from-sip,706,2) exited non-zero on 'SIP/7066-36f1' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1675 pbx_extension_helper: Launching 'NoOp' -- Executing [h@from-sip:1] NoOp("SIP/7066-36f1", "Reached Hangup Extension") in new stack Jun 22 23:03:48 DEBUG[30931]: pbx.c:1675 pbx_extension_helper: Launching 'Hangup' -- Executing [h@from-sip:2] Hangup("SIP/7066-36f1", "") in new stack Jun 22 23:03:48 DEBUG[30931]: pbx.c:2378 __ast_pbx_run: Spawn extension (from-sip,h,2) exited non-zero on 'SIP/7066-36f1' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '"xlite" <7066>' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '7066' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '706' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'from-sip' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/7066-36f1' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/706-2ba0' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Hangup' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-22 23:02:58' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-22 23:02:58' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-22 23:03:48' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '50' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '50' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1151013778.0' Jun 22 23:03:48 DEBUG[30931]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 22 23:03:48 DEBUG[30904]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 706 Jun 22 23:03:48 DEBUG[30904]: devicestate.c:189 do_state_change: Changing state for SIP/706 - state 1 (Not in use) Jun 22 23:03:48 DEBUG[30936]: app_queue.c:529 changethread: Device 'SIP/706' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Huh? Child handler, but nobody there? Warning: [DataDirect][ODBC Progress OpenEdge Wire Protocol driver]File not found 'IVPG.LIC'.[DataDirect][ODBC Progress OpenEdge Wire Protocol driver]You are not licensed to use this DataDirect Technologies ODBC Driver under the license you have purchased. If you wish to purchase a license for use with this application, then you may use this driver for a period of 15 days, during which time you are required to obtain a license. You can order a license for a DataDirect Technologies ODBC Driver for use with this application by calling DataDirect Technologies at 800-876-3101 in North America and +44 1727 812812 elsewhere. Thank you for your cooperation. Jun 22 23:03:48 DEBUG[30931]: channel.c:1493 ast_hangup: Hanging up channel 'SIP/7066-36f1' Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:3141 sip_hangup: Hangup call SIP/7066-36f1, SIP callid 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.) Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:3149 sip_hangup: update_call_counter(7066) - decrement call limit counter on hangup Jun 22 23:03:48 DEBUG[30931]: chan_sip.c:2841 update_call_counter: Updating call counter for incoming call Jun 22 23:03:48 DEBUG[30904]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 7066 Jun 22 23:03:48 DEBUG[30904]: devicestate.c:189 do_state_change: Changing state for SIP/7066 - state 1 (Not in use) Jun 22 23:03:48 DEBUG[30939]: app_queue.c:529 changethread: Device 'SIP/7066' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. <-- SIP read from 192.168.0.200:52838: SIP/2.0 200 OK Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2d10adb2;rport From: "xlite" ;tag=as26722de4 To: ;tag=000785993d3d05b0143670ee-2a075828 Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 Date: Thu, 22 Jun 2006 22:03:48 GMT CSeq: 103 BYE Server: CSCO/7 Content-Length: 0 Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 90.0.0.62:5060;branch=z9hG4bK2d10adb2;rport (60) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: From: "xlite" ;tag=as26722de4 (49) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=000785993d3d05b0143670ee-2a075828 (70) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 020de1d54ccecb9d2361709321e49ff6@90.0.0.62 (51) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: Date: Thu, 22 Jun 2006 22:03:48 GMT (35) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: CSeq: 103 BYE (13) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 0 (17) Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #30 Jun 22 23:03:49 DEBUG[30916]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' of Request 103: Match Not Found Really destroying SIP dialog '020de1d54ccecb9d2361709321e49ff6@90.0.0.62' Method: ACK Really destroying SIP dialog '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' Method: ACK <-- SIP read from 192.168.0.12:54990: BYE sip:706@90.0.0.62 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5c1ce95e52274c5c-1--d87543-;rport Max-Forwards: 70 Contact: To: "706";tag=as1b49e198 From: "Foxtrot";tag=1221994f Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 5 BYE Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="b8f07e34d3b274202aad8ec4947cc0ca",algorithm=MD5 User-Agent: X-Lite release 1002tx stamp 29712 Reason: SIP;description="User Hung Up" Content-Length: 0 Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 0: BYE sip:706@90.0.0.62 SIP/2.0 (29) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5c1ce95e52274c5c-1--d87543-;rport (91) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 2: Max-Forwards: 70 (16) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 3: Contact: (38) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 4: To: "706";tag=as1b49e198 (55) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 5: From: "Foxtrot";tag=1221994f (60) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 6: Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. (69) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 7: CSeq: 5 BYE (11) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 8: Proxy-Authorization: Digest username="7066",realm="asterisk",nonce="746ea9c7",uri="sip:706@90.0.0.62",response="b8f07e34d3b274202aad8ec4947cc0ca",algorithm=MD5 (159) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 9: User-Agent: X-Lite release 1002tx stamp 29712 (45) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 10: Reason: SIP;description="User Hung Up" (38) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 11: Content-Length: 0 (17) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4307 parse_request: Header 12: (0) --- (12 headers 0 lines)--- Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:4087 sip_alloc: Allocating new SIP dialog for 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. - BYE (No RTP) Jun 22 23:03:54 DEBUG[30916]: chan_sip.c:13965 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.0.12 : 54990 (NAT) Transmitting (NAT) to 192.168.0.12:54990: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.12:54990;branch=z9hG4bK-d87543-5c1ce95e52274c5c-1--d87543-;received=192.168.0.12;rport=54990 From: "Foxtrot";tag=1221994f To: "706";tag=as1b49e198 Call-ID: 5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc. CSeq: 5 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- Really destroying SIP dialog '5b70007426044b7aYjk3MTJlMTgzYzk4NjQ0NzhmZTJiN2VmNmE4OTgwZTc.' Method: BYE stop now Beginning asterisk shutdown.... Executing last minute cleanups == Destroying musiconhold processes Asterisk cleanly ending (0). [root@foxtrot asterisk]#