[root@foxtrot asterisk]# asterisk -vvvvcg == 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 23 18:21:31 NOTICE[3990]: res_odbc.c:220 load_odbc_config: Adding ENV var: INFORMIXSERVER=my_special_database Jun 23 18:21:31 NOTICE[3990]: res_odbc.c:220 load_odbc_config: Adding ENV var: INFORMIXDIR=/opt/informix Jun 23 18:21:31 NOTICE[3990]: res_odbc.c:220 load_odbc_config: Adding ENV var: ODBCINI=/etc/odbc.ini Jun 23 18:21:31 NOTICE[3990]: res_odbc.c:490 odbc_obj_connect: Connecting debtnet Jun 23 18:21:31 NOTICE[3990]: res_odbc.c:504 odbc_obj_connect: res_odbc: Connected to debtnet [debtnet] Jun 23 18:21:31 NOTICE[3990]: res_odbc.c:292 load_odbc_config: Registered ODBC class 'debtnet' dsn->[debtnet] Jun 23 18:21:31 NOTICE[3990]: res_odbc.c:667 load_module: res_odbc loaded. [res_config_odbc.so] => (ODBC Configuration) Jun 23 18:21:31 NOTICE[3990]: config.c:854 ast_config_engine_register: Registered Config Engine odbc res_config_odbc loaded. Jun 23 18:21:31 DEBUG[3990]: loader.c:389 fixup: ---- fixup (load_modules): 2 modules, 0 new --- Jun 23 18:21:31 DEBUG[3990]: loader.c:394 fixup: ---- fixup: cycle 0 --- Jun 23 18:21:31 DEBUG[3990]: 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 23 18:21:31 NOTICE[3990]: 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 23 18:21:31 NOTICE[3990]: res_jabber.c:2282 load_module: res_jabber.so loaded. [res_config_pgsql.so]JABBER: reconnecting. => (Postgresql RealTime Configuration Driver) Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:687 parse_config: Postgresql RealTime Host: Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:688 parse_config: Postgresql RealTime Port: 5432 Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:692 parse_config: Postgresql RealTime User: Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:693 parse_config: Postgresql RealTime Password: Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:694 parse_config: Postgresql RealTime DBName: Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:749 pgsql_reconnect: 100 connInfo=host= port=5432 dbname= user= password= Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:751 pgsql_reconnect: 100 connInfo=host= port=5432 dbname= user= password= Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:754 pgsql_reconnect: pgsqlConn=0x9c0cdc8 Jun 23 18:21:31 DEBUG[3990]: res_config_pgsql.c:756 pgsql_reconnect: Postgresql RealTime: Successfully connected to database. Jun 23 18:21:31 NOTICE[3990]: 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 23 18:21:31 WARNING[3990]: 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 23 18:21:31 DEBUG[3990]: pbx.c:3510 ast_merge_contexts_and_delete: must remove any reg pbx_config Jun 23 18:21:31 DEBUG[3990]: 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 23 18:21:31 NOTICE[3990]: pbx_ael.c:3453 pbx_load_module: Starting AEL load process. Jun 23 18:21:31 NOTICE[3990]: pbx_ael.c:3460 pbx_load_module: AEL load process: calculated config file name '/etc/asterisk/extensions.ael'. Jun 23 18:21:31 ERROR[3990]: ael.flex:558 ael2_parse: File /etc/asterisk/extensions.ael could not be opened Jun 23 18:21:31 NOTICE[3990]: pbx_ael.c:3463 pbx_load_module: AEL load process: parsed config file name '/etc/asterisk/extensions.ael'. Jun 23 18:21:31 ERROR[3990]: 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 23 18:21:31 DEBUG[3990]: 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 23 18:21:31 WARNING[3990]: 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 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 1, with 0 conference users -- Registered channel 1, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 2, with 0 conference users -- Registered channel 2, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 3, with 0 conference users -- Registered channel 3, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 4, with 0 conference users -- Registered channel 4, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 5, with 0 conference users -- Registered channel 5, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 6, with 0 conference users -- Registered channel 6, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 7, with 0 conference users -- Registered channel 7, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 8, with 0 conference users -- Registered channel 8, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1357 update_conf: Updated conferencing on 9, with 0 conference users -- Registered channel 9, PRI Signalling signalling Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1502 set_actual_txgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: chan_zap.c:1520 set_actual_rxgain: Failed to read gains: Invalid argument Jun 23 18:21:31 DEBUG[3990]: 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.159:5060 for 3600 Jun 23 18:21:31 DEBUG[3990]: db.c:197 ast_db_get: Unable to find key '7067' in family 'SIP/Registry' Jun 23 18:21:31 DEBUG[3990]: db.c:197 ast_db_get: Unable to find key '7066' in family 'SIP/Registry' -- SIP Seeding peer from astdb: '707' at 707@192.168.6.100:5060 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 23 18:21:31 DEBUG[3990]: app_voicemail.c:6361 load_config: VM Review Option disabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6368 load_config: VM Temperary Greeting Reminder Option disabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6376 load_config: VM Operator break disabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6382 load_config: VM CID Info before msg disabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6388 load_config: Send Voicemail msg disabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6394 load_config: ENVELOPE before msg enabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6400 load_config: Duration info before msg enabled globally Jun 23 18:21:31 DEBUG[3990]: app_voicemail.c:6415 load_config: We are not going to skip to the next msg after save/delete Jun 23 18:21:31 WARNING[3990]: 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 [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 2 [func_cut.so] => (Cut out information from a string) == Registered custom function CUT == Registered custom function SORT [cdr_odbc.so] => (ODBC CDR Backend) Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:257 odbc_load_module: cdr_odbc: starting odbc load == Parsing '/etc/asterisk/cdr_odbc.conf': Found Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:266 odbc_load_module: cdr_odbc: #1 Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:273 odbc_load_module: cdr_odbc: #2 Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:279 odbc_load_module: cdr_odbc: #3 Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:287 odbc_load_module: cdr_odbc: #4 Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:295 odbc_load_module: cdr_odbc: #5 Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:306 odbc_load_module: cdr_odbc: #6 Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:317 odbc_load_module: cdr_odbc: #7 Jun 23 18:21:31 DEBUG[3990]: cdr_odbc.c:322 odbc_load_module: cdr_odbc: Logging uniqueid Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:331 odbc_load_module: cdr_odbc: #8 Jun 23 18:21:31 DEBUG[3990]: cdr_odbc.c:336 odbc_load_module: cdr_odbc: Logging in GMT Jun 23 18:21:31 NOTICE[3990]: cdr_odbc.c:345 odbc_load_module: cdr_odbc: #9 Jun 23 18:21:31 NOTICE[3990]: 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 23 18:21:31 NOTICE[3990]: cdr_odbc.c:374 odbc_load_module: cdr_odbc: #11 Jun 23 18:21:31 NOTICE[3990]: 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 23 18:21:31 DEBUG[3990]: cdr_csv.c:126 load_config: logging time in GMT Jun 23 18:21:31 DEBUG[3990]: cdr_csv.c:134 load_config: logging CDR field UNIQUEID Jun 23 18:21:31 DEBUG[3990]: cdr_csv.c:142 load_config: logging CDR user-defined field [codec_ilbc.so] => (iLBC/PCM16 (signed linear) Codec Translator) == Registered translator 'ilbctolin' from format ilbc to slin, cost 4 == Registered translator 'lintoilbc' from format slin to ilbc, cost 16 [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 [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 23 18:21:31 WARNING[3990]: 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 23 18:21:31 DEBUG[3990]: loader.c:389 fixup: ---- fixup (load_modules): 153 modules, 0 new --- Jun 23 18:21:31 DEBUG[3990]: loader.c:394 fixup: ---- fixup: cycle 0 --- Jun 23 18:21:31 DEBUG[3990]: loader.c:425 fixup: ---- fixup complete --- == Manager registered action DBGet == Manager registered action DBPut == Parsing '/etc/asterisk/enum.conf': Found Asterisk Ready. *CLI> == Primary D-Channel on span 1 up *CLI> set debug 4 Core debug was 0 and is now 4 *CLI> sip debug SIP Debugging enabled -- Accepting call from '07803034440' to '444607' on channel 0/1, span 1 Jun 23 18:22:04 DEBUG[4003]: chan_zap.c:1388 zt_enable_ec: Enabled echo cancellation on channel 1 Jun 23 18:22:04 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for Zap/1 - state 2 (In use) Jun 23 18:22:04 DEBUG[4021]: pbx.c:1675 pbx_extension_helper: Launching 'Goto' -- Executing [444607@isdn10:1] Goto("Zap/1-1", "common|707|1") in new stack -- Goto (common,707,1) Jun 23 18:22:04 DEBUG[4021]: pbx.c:1675 pbx_extension_helper: Launching 'Answer' -- Executing [707@common:1] Answer("Zap/1-1", "") in new stack Jun 23 18:22:04 DEBUG[3994]: channel.c:857 channel_find_locked: Avoiding initial deadlock for channel '0x9cc9db0' Jun 23 18:22:04 DEBUG[4021]: pbx.c:1675 pbx_extension_helper: Launching 'Dial' -- Executing [707@common:2] Dial("Zap/1-1", "SIP/707") in new stack Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:14588 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4087 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:2476 create_addr_from_peer: Setting NAT on RTP to Off Jun 23 18:22:04 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for Zap/1 - state 2 (In use) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:3576 sip_new: *** Our native formats are 0x4 (ulaw) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:3577 sip_new: *** Joint capabilities are 0x0 (nothing) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:3578 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:3579 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:3581 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:3602 sip_new: This channel will not be able to handle video. Jun 23 18:22:04 DEBUG[4021]: rtp.c:1388 ast_rtp_make_compatible: Channel 'Zap/1-1' has no RTP, not doing anything Jun 23 18:22:04 DEBUG[4021]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-common-707-2. Jun 23 18:22:04 DEBUG[4021]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-common-707-1. Jun 23 18:22:04 DEBUG[4021]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-isdn10-444607-1. Jun 23 18:22:04 DEBUG[4021]: channel.c:2937 ast_channel_inherit_variables: Not copying variable CALLEDTON. Jun 23 18:22:04 DEBUG[4021]: channel.c:2937 ast_channel_inherit_variables: Not copying variable ANI2. Jun 23 18:22:04 DEBUG[4021]: channel.c:2937 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY. Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:2678 sip_call: Outgoing Call for 707 Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:2686 sip_call: Our T38 capability (0), joint T38 capability (0) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x8 (alaw) Audio is at 192.168.6.6 port 10200 Adding codec 0x8 (alaw) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x2 (gsm) to SDP Adding non-codec 0x1 (telephone-event) to SDP Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:707@192.168.6.100:5060 SIP/2.0 (41) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2;rport (62) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 2: From: "07803034440" ;tag=as465a4e16 (64) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 3: To: (32) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 4: Contact: (38) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 5: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 8: Max-Forwards: 70 (16) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 9: Date: Fri, 23 Jun 2006 17:22:04 GMT (35) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 11: Supported: replaces (19) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 12: Content-Type: application/sdp (29) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 13: Content-Length: 271 (19) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4307 parse_request: Header 14: (0) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: o=root 3990 3990 IN IP4 192.168.6.6 (35) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: s=session (9) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.6 (20) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: m=audio 10200 RTP/AVP 8 0 3 101 (31) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-16 (15) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=silenceSupp:off - - - - (25) Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 192.168.6.100:5060: INVITE sip:707@192.168.6.100:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2;rport From: "07803034440" ;tag=as465a4e16 To: Contact: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Fri, 23 Jun 2006 17:22:04 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 271 v=0 o=root 3990 3990 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 10200 RTP/AVP 8 0 3 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- Jun 23 18:22:04 DEBUG[4021]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #15 -- Called 707 Jun 23 18:22:04 DEBUG[4021]: channel.c:2492 set_format: Set channel SIP/707-2faa to read format alaw Jun 23 18:22:04 DEBUG[4021]: channel.c:2492 set_format: Set channel Zap/1-1 to write format alaw Jun 23 18:22:04 DEBUG[4021]: channel.c:2492 set_format: Set channel Zap/1-1 to read format ulaw Jun 23 18:22:04 DEBUG[4021]: channel.c:2492 set_format: Set channel SIP/707-2faa to write format ulaw Jun 23 18:22:04 DEBUG[4022]: app_queue.c:529 changethread: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jun 23 18:22:04 DEBUG[4023]: app_queue.c:529 changethread: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. <-- SIP read from 192.168.6.100:5060: SIP/2.0 100 Trying To: From: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 INVITE Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2 Server: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 100 Trying (18) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: To: (32) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "07803034440" ;tag=as465a4e16 (64) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: CSeq: 102 INVITE (16) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2 (56) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Server: Sipura/SPA941-4.1.8 (27) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Content-Length: 0 (17) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:2017 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #15 - INVITE (got response) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:2026 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '241cb33e679ce2a43c4beab66ee38386@192.168.6.6' Request 102: Found Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:11140 handle_response_invite: SIP response 100 to standard invite <-- SIP read from 192.168.6.100:5060: SIP/2.0 180 Ringing To: ;tag=e8409661b75ab035i0 From: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 INVITE Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2 Server: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: To: ;tag=e8409661b75ab035i0 (55) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "07803034440" ;tag=as465a4e16 (64) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: CSeq: 102 INVITE (16) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2 (56) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Server: Sipura/SPA941-4.1.8 (27) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Content-Length: 0 (17) Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:2026 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '241cb33e679ce2a43c4beab66ee38386@192.168.6.6' Request 102: Found Jun 23 18:22:04 DEBUG[4006]: chan_sip.c:11140 handle_response_invite: SIP response 180 to standard invite Jun 23 18:22:04 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 707 Jun 23 18:22:04 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/707 - state 1 (Not in use) -- SIP/707-2faa is ringing Jun 23 18:22:04 DEBUG[4021]: rtp.c:1313 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything Jun 23 18:22:04 DEBUG[4021]: chan_zap.c:4872 zt_indicate: Requested indication 3 on channel Zap/1-1 Jun 23 18:22:04 DEBUG[4024]: app_queue.c:529 changethread: Device 'SIP/707' 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.6.100:5060: SIP/2.0 200 OK To: ;tag=e8409661b75ab035i0 From: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 INVITE Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2 Contact: "707 Test" Server: Sipura/SPA941-4.1.8 Content-Length: 208 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Content-Type: application/sdp v=0 o=- 559267 559267 IN IP4 192.168.6.100 s=- c=IN IP4 192.168.6.100 t=0 0 m=audio 16444 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: To: ;tag=e8409661b75ab035i0 (55) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "07803034440" ;tag=as465a4e16 (64) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: CSeq: 102 INVITE (16) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK308527b2 (56) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Contact: "707 Test" (48) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Server: Sipura/SPA941-4.1.8 (27) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 208 (19) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Type: application/sdp (29) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: (0) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 559267 559267 IN IP4 192.168.6.100 (38) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.100 (22) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 101 (27) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) --- (11 headers 11 lines)--- Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:1966 __sip_ack: Acked pending invite 102 Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '241cb33e679ce2a43c4beab66ee38386@192.168.6.6' of Request 102: Match Not Found Jun 23 18:22:07 DEBUG[4006]: 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.6.100:16444 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/707-2faa 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.6.100:16444 Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:7571 build_route: build_route: Contact hop: "707 Test" list_route: hop: Jun 23 18:22:07 DEBUG[4006]: chan_sip.c:5318 reqprep: Strict routing enforced for session 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.6.100, port 5060 Transmitting (no NAT) to 192.168.6.100:5060: ACK sip:707@192.168.6.100:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK4228cf49;rport From: "07803034440" ;tag=as465a4e16 To: ;tag=e8409661b75ab035i0 Contact: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/707-2faa answered Zap/1-1 Jun 23 18:22:07 DEBUG[4021]: rtp.c:1313 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything Jun 23 18:22:07 DEBUG[4021]: chan_zap.c:4872 zt_indicate: Requested indication -1 on channel Zap/1-1 Jun 23 18:22:07 DEBUG[4021]: channel.c:2492 set_format: Set channel Zap/1-1 to read format ulaw Jun 23 18:22:07 DEBUG[4021]: channel.c:2492 set_format: Set channel SIP/707-2faa to write format ulaw Jun 23 18:22:07 DEBUG[4021]: channel.c:2492 set_format: Set channel SIP/707-2faa to read format alaw Jun 23 18:22:07 DEBUG[4021]: channel.c:2492 set_format: Set channel Zap/1-1 to write format alaw Jun 23 18:22:07 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 707 Jun 23 18:22:07 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/707 - state 1 (Not in use) Jun 23 18:22:07 DEBUG[4025]: app_queue.c:529 changethread: Device 'SIP/707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 23 18:22:07 DEBUG[4021]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.6.100:5060: INVITE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 560102 560102 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16444 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6 SIP/2.0 (42) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 (59) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 30 (11) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 226 (19) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Type: application/sdp (29) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560102 560102 IN IP4 192.168.6.100 (38) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 8 101 (29) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (12 headers 12 lines)--- Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.100 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:16444 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/707-2faa 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:16444 Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 23 18:22:12 DEBUG[4006]: 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 Zap/1-1 Jun 23 18:22:12 DEBUG[4006]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 Jun 23 18:22:12 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-2faa: New call is UP.... Jun 23 18:22:12 DEBUG[4021]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 23 18:22:12 DEBUG[4021]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 23 18:22:12 DEBUG[4021]: channel.c:2492 set_format: Set channel Zap/1-1 to write format ulaw Jun 23 18:22:12 DEBUG[4021]: res_musiconhold.c:251 ast_moh_files_next: Zap/1-1 Opened file 0 '/var/lib/asterisk/sounds/custom/moh/track07' <-- SIP read from 192.168.6.100:5060: INVITE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 560102 560102 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16444 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6 SIP/2.0 (42) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 (59) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 30 (11) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 226 (19) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Type: application/sdp (29) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560102 560102 IN IP4 192.168.6.100 (38) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 8 101 (29) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (12 headers 12 lines)--- Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:13984 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:12832 handle_request_invite: Got a SIP re-transmit of INVITE for call 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 Jun 23 18:22:13 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-2faa: New call is UP.... <-- SIP read from 192.168.6.100:5060: INVITE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 560102 560102 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16444 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6 SIP/2.0 (42) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 (59) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 30 (11) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 226 (19) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Type: application/sdp (29) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560102 560102 IN IP4 192.168.6.100 (38) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 8 101 (29) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (12 headers 12 lines)--- Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:13984 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:12832 handle_request_invite: Got a SIP re-transmit of INVITE for call 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 Jun 23 18:22:14 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-2faa: New call is UP.... <-- SIP read from 192.168.6.100:5060: INVITE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 560102 560102 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16444 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6 SIP/2.0 (42) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 (59) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 30 (11) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 226 (19) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Type: application/sdp (29) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560102 560102 IN IP4 192.168.6.100 (38) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 8 101 (29) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (12 headers 12 lines)--- Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:13984 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:12832 handle_request_invite: Got a SIP re-transmit of INVITE for call 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-2faa: New call is UP.... <-- SIP read from 192.168.6.100:5060: INVITE sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5714c338 From: "707 Test" ;tag=4122a4559a24df87o0 To: Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 240 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 397 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Content-Type: application/sdp v=0 o=- 560473 560473 IN IP4 192.168.6.100 s=- c=IN IP4 192.168.6.100 t=0 0 m=audio 16446 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:747@192.168.6.6 SIP/2.0 (34) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5714c338 (59) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: (25) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 240 (12) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 397 (19) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: Content-Type: application/sdp (29) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560473 560473 IN IP4 192.168.6.100 (38) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.100 (22) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16446 RTP/AVP 0 2 4 8 18 96 97 98 101 (45) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:4 G723/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:18 G729a/8000 (22) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) --- (13 headers 18 lines)--- Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4087 sip_alloc: Allocating new SIP dialog for ad786ed-e6079dcf@192.168.6.100 - INVITE (With RTP) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.100 : 5060 (no NAT) Using INVITE request as basis request - ad786ed-e6079dcf@192.168.6.100 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:8608 check_user_full: Setting NAT on RTP to Off Reliably Transmitting (no NAT) to 192.168.6.100:5060: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5714c338;received=192.168.6.100 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as790cb66a Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Proxy-Authenticate: Digest realm="asterisk", nonce="17ee85fb" Content-Length: 0 --- Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #18 Scheduling destruction of SIP dialog 'ad786ed-e6079dcf@192.168.6.100' in 32000 ms (Method: INVITE) Found user '707' <-- SIP read from 192.168.6.100:5060: ACK sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5714c338 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as790cb66a Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 101 ACK Max-Forwards: 70 Contact: "707 Test" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: ACK sip:747@192.168.6.6 SIP/2.0 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5714c338 (59) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=as790cb66a (40) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 ACK (13) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Content-Length: 0 (17) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on 'ad786ed-e6079dcf@192.168.6.100' of Response 101: Match Not Found <-- SIP read from 192.168.6.100:5060: INVITE sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-f60269b5 From: "707 Test" ;tag=4122a4559a24df87o0 To: Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 102 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="86b2a5d4086ba3424a26bdd7b5138072" Contact: "707 Test" Expires: 240 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 397 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Content-Type: application/sdp v=0 o=- 560473 560473 IN IP4 192.168.6.100 s=- c=IN IP4 192.168.6.100 t=0 0 m=audio 16446 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:747@192.168.6.6 SIP/2.0 (34) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-f60269b5 (59) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: (25) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 102 INVITE (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="86b2a5d4086ba3424a26bdd7b5138072" (160) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: "707 Test" (48) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Expires: 240 (12) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Length: 397 (19) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER (61) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 13: Content-Type: application/sdp (29) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 14: (0) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560473 560473 IN IP4 192.168.6.100 (38) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.100 (22) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16446 RTP/AVP 0 2 4 8 18 96 97 98 101 (45) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:2 G726-32/8000 (23) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:4 G723/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:18 G729a/8000 (22) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:96 G726-40/8000 (24) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:97 G726-24/8000 (24) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:98 G726-16/8000 (24) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) --- (14 headers 18 lines)--- Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.100 : 5060 (no NAT) Using INVITE request as basis request - ad786ed-e6079dcf@192.168.6.100 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:8608 check_user_full: Setting NAT on RTP to Off Found user '707' Found RTP audio format 0 Found RTP audio format 2 Found RTP audio format 4 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 96 Found RTP audio format 97 Found RTP audio format 98 Found RTP audio format 101 Peer audio RTP is at port 192.168.6.100:16446 Found description format PCMU for ID 0 Found description format G726-32 for ID 2 Found description format G723 for ID 4 Found description format PCMA for ID 8 Found description format G729a for ID 18 Found description format G726-40 for ID 96 Found description format G726-24 for ID 97 Found description format G726-16 for ID 98 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer Jun 23 18:22:16 DEBUG[4006]: 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.6.100:16446 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:12782 handle_request_invite: Checking SIP call limits for device 707 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:2841 update_call_counter: Updating call counter for incoming call Looking for 747 in from-sip (domain 192.168.6.6) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:3576 sip_new: *** Our native formats are 0x4 (ulaw) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:3577 sip_new: *** Joint capabilities are 0xe (gsm|ulaw|alaw) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:3578 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:3579 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:3602 sip_new: This channel will not be able to handle video. Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:7571 build_route: build_route: Contact hop: "707 Test" list_route: hop: Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:12852 handle_request_invite: SIP/707-f997: New call is still down.... Trying... Transmitting (no NAT) to 192.168.6.100:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-f60269b5;received=192.168.6.100 From: "707 Test" ;tag=4122a4559a24df87o0 To: Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 102 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 23 18:22:16 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 707 Jun 23 18:22:16 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/707 - state 1 (Not in use) Jun 23 18:22:16 DEBUG[4026]: pbx.c:1675 pbx_extension_helper: Launching 'Answer' -- Executing [747@from-sip:1] Answer("SIP/707-f997", "") in new stack Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3282 sip_answer: SIP answering channel: SIP/707-f997 Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.6.6 port 19276 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 23 18:22:16 DEBUG[4026]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.6.100:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-f60269b5;received=192.168.6.100 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 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: 271 v=0 o=root 3990 3990 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 19276 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 23 18:22:16 DEBUG[4026]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #20 Jun 23 18:22:16 DEBUG[4026]: pbx.c:1675 pbx_extension_helper: Launching 'Dial' -- Executing [747@from-sip:2] Dial("SIP/707-f997", "SIP/747") in new stack Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:14588 sip_request_call: Asked to create a SIP channel with formats: 0x4 (ulaw) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4087 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:2476 create_addr_from_peer: Setting NAT on RTP to Off Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3576 sip_new: *** Our native formats are 0x4 (ulaw) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3577 sip_new: *** Joint capabilities are 0x0 (nothing) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3578 sip_new: *** Our capabilities are 0xe (gsm|ulaw|alaw) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3579 sip_new: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3581 sip_new: *** Our preferred formats from the incoming channel are 0x4 (ulaw) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:3602 sip_new: This channel will not be able to handle video. Jun 23 18:22:16 DEBUG[4026]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-from-sip-747-2. Jun 23 18:22:16 DEBUG[4026]: channel.c:2937 ast_channel_inherit_variables: Not copying variable STACK-from-sip-747-1. Jun 23 18:22:16 DEBUG[4026]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPCALLID. Jun 23 18:22:16 DEBUG[4026]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPUSERAGENT. Jun 23 18:22:16 DEBUG[4026]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. Jun 23 18:22:16 DEBUG[4026]: channel.c:2937 ast_channel_inherit_variables: Not copying variable SIPURI. Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:2678 sip_call: Outgoing Call for 747 Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:2686 sip_call: Our T38 capability (0), joint T38 capability (0) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: False Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x4 (ulaw) Audio is at 192.168.6.6 port 16106 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 23 18:22:16 DEBUG[4026]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:747@192.168.6.159:5060 SIP/2.0 (41) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport (62) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 2: From: "Test 707" ;tag=as222635ed (53) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 3: To: (32) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 4: Contact: (30) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 5: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 (53) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 7: User-Agent: Asterisk PBX (24) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 8: Max-Forwards: 70 (16) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 9: Date: Fri, 23 Jun 2006 17:22:16 GMT (35) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 11: Supported: replaces (19) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 12: Content-Type: application/sdp (29) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 13: Content-Length: 271 (19) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4307 parse_request: Header 14: (0) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: o=root 3990 3990 IN IP4 192.168.6.6 (35) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: s=session (9) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.6 (20) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: m=audio 16106 RTP/AVP 0 8 3 101 (31) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: a=rtpmap:3 GSM/8000 (19) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-16 (15) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: Line: a=silenceSupp:off - - - - (25) Jun 23 18:22:16 DEBUG[4026]: chan_sip.c:4339 parse_request: <-- SIP read from 192.168.6.100:5060: ACK sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-3f18d9ae From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 102 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="4ea677cbf469d5fc65dc17537cb2df8c" Contact: "707 Test" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Line: a=sendrecv (10) Reliably Transmitting (no NAT) to 192.168.6.159:5060: INVITE sip:747@192.168.6.159:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport From: "Test 707" ;tag=as222635ed To: Contact: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Fri, 23 Jun 2006 17:22:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 271 v=0 o=root 3990 3990 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 16106 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 23 18:22:16 DEBUG[4026]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #21 -- Called 747 Jun 23 18:22:16 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/747-8ddb to read format ulaw Jun 23 18:22:16 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/707-f997 to write format ulaw Jun 23 18:22:16 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/707-f997 to read format ulaw Jun 23 18:22:16 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/747-8ddb to write format ulaw Jun 23 18:22:16 DEBUG[4027]: app_queue.c:529 changethread: Device 'SIP/707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 23 18:22:16 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 707 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: ACK sip:747@192.168.6.6 SIP/2.0 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-3f18d9ae (59) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=as0576aac0 (40) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 102 ACK (13) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="4ea677cbf469d5fc65dc17537cb2df8c" (160) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: "707 Test" (48) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #20 Jun 23 18:22:16 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on 'ad786ed-e6079dcf@192.168.6.100' of Response 102: Match Not Found Jun 23 18:22:16 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/707 - state 1 (Not in use) Jun 23 18:22:16 DEBUG[4028]: app_queue.c:529 changethread: Device 'SIP/707' 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.6.159:50512: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport From: "Test 707" ;tag=as222635ed To: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 Date: Fri, 23 Jun 2006 17:22:17 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 100 Trying (18) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport (62) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "Test 707" ;tag=as222635ed (53) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: (32) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 (53) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Date: Fri, 23 Jun 2006 17:22:17 GMT (35) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Content-Length: 0 (17) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:2017 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #21 - INVITE (got response) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:2026 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '00fb5bc2314b80135327444a639f4bfc@192.168.6.6' Request 102: Found Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:11140 handle_response_invite: SIP response 100 to standard invite <-- SIP read from 192.168.6.159:50513: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport From: "Test 707" ;tag=as222635ed To: ;tag=00059bf197bc000a42388b02-57441a6e Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 Date: Fri, 23 Jun 2006 17:22:17 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Length: 0 Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 180 Ringing (19) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport (62) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "Test 707" ;tag=as222635ed (53) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=00059bf197bc000a42388b02-57441a6e (70) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 (53) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Date: Fri, 23 Jun 2006 17:22:17 GMT (35) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Content-Length: 0 (17) Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: (0) --- (10 headers 0 lines)--- Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:2026 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '00fb5bc2314b80135327444a639f4bfc@192.168.6.6' Request 102: Found Jun 23 18:22:17 DEBUG[4006]: chan_sip.c:11140 handle_response_invite: SIP response 180 to standard invite -- SIP/747-8ddb is ringing Jun 23 18:22:17 DEBUG[4026]: channel.c:2172 ast_indicate_data: Driver for channel 'SIP/707-f997' does not support indication 3, emulating it Jun 23 18:22:17 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/707-f997 to write format slin Jun 23 18:22:17 DEBUG[4026]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 23 18:22:17 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 747 Jun 23 18:22:17 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/747 - state 1 (Not in use) Jun 23 18:22:17 DEBUG[4029]: app_queue.c:529 changethread: Device 'SIP/747' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 23 18:22:17 DEBUG[4026]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 23 18:22:17 DEBUG[4026]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 23 18:22:17 DEBUG[4026]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.6.100:5060: INVITE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 560102 560102 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16444 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6 SIP/2.0 (42) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 (59) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 30 (11) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 226 (19) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Type: application/sdp (29) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560102 560102 IN IP4 192.168.6.100 (38) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 8 101 (29) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (12 headers 12 lines)--- Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:13984 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:12832 handle_request_invite: Got a SIP re-transmit of INVITE for call 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 Jun 23 18:22:20 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-2faa: New call is UP.... <-- SIP read from 192.168.6.159:50514: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport From: "Test 707" ;tag=as222635ed To: ;tag=00059bf197bc000a42388b02-57441a6e Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 Date: Fri, 23 Jun 2006 17:22:21 GMT CSeq: 102 INVITE Server: CSCO/7 Contact: Content-Type: application/sdp Content-Length: 199 v=0 o=Cisco-SIPUA 14467 14837 IN IP4 192.168.6.159 s=SIP Call c=IN IP4 192.168.6.159 t=0 0 m=audio 21794 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK2392a69c;rport (62) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "Test 707" ;tag=as222635ed (53) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=00059bf197bc000a42388b02-57441a6e (70) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 (53) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Date: Fri, 23 Jun 2006 17:22:21 GMT (35) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: CSeq: 102 INVITE (16) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Server: CSCO/7 (14) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: (37) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Content-Type: application/sdp (29) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 199 (19) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: (0) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=Cisco-SIPUA 14467 14837 IN IP4 192.168.6.159 (46) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=SIP Call (10) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.159 (22) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 21794 RTP/AVP 0 101 (27) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) --- (11 headers 9 lines)--- Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:1966 __sip_ack: Acked pending invite 102 Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on '00fb5bc2314b80135327444a639f4bfc@192.168.6.6' of Request 102: Match Not Found Jun 23 18:22:21 DEBUG[4006]: 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.6.159:21794 Found description format PCMU for ID 0 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/747-8ddb 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.6.159:21794 Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:4894 process_sdp: We have an owner, now see if we need to change this call Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:7571 build_route: build_route: Contact hop: list_route: hop: Jun 23 18:22:21 DEBUG[4006]: chan_sip.c:5318 reqprep: Strict routing enforced for session 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.6.159, port 5060 Transmitting (no NAT) to 192.168.6.159:5060: ACK sip:747@192.168.6.159:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK110babb6;rport From: "Test 707" ;tag=as222635ed To: ;tag=00059bf197bc000a42388b02-57441a6e Contact: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- -- SIP/747-8ddb answered SIP/707-f997 Jun 23 18:22:21 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/707-f997 to write format ulaw Jun 23 18:22:21 DEBUG[4026]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 23 18:22:21 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/707-f997 to read format ulaw Jun 23 18:22:21 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/747-8ddb to write format ulaw Jun 23 18:22:21 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/747-8ddb to read format ulaw Jun 23 18:22:21 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/707-f997 to write format ulaw Jun 23 18:22:21 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 747 Jun 23 18:22:21 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/747 - state 1 (Not in use) Jun 23 18:22:21 DEBUG[4030]: app_queue.c:529 changethread: Device 'SIP/747' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 23 18:22:21 DEBUG[4026]: rtp.c:2341 ast_rtp_write: Ooh, format changed from unknown to ulaw <-- SIP read from 192.168.6.100:5060: INVITE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 101 INVITE Max-Forwards: 70 Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 560102 560102 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16444 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:07803034440@192.168.6.6 SIP/2.0 (42) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-7e1854a7 (59) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 101 INVITE (16) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Contact: "707 Test" (48) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Expires: 30 (11) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 226 (19) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Type: application/sdp (29) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: (0) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 560102 560102 IN IP4 192.168.6.100 (38) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16444 RTP/AVP 0 8 101 (29) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (12 headers 12 lines)--- Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:13984 handle_request: Ignoring SIP message because of retransmit (INVITE Seqno 101, ours 101) Ignoring this INVITE request Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:12832 handle_request_invite: Got a SIP re-transmit of INVITE for call 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-2faa: New call is UP.... <-- SIP read from 192.168.6.100:5060: BYE sip:07803034440@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-11c406cf From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 BYE Max-Forwards: 70 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: BYE sip:07803034440@192.168.6.6 SIP/2.0 (39) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-11c406cf (59) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=e8409661b75ab035i0 (57) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "07803034440" ;tag=as465a4e16 (62) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 (53) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 102 BYE (13) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 0 (17) Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 23 18:22:28 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.6.100 : 5060 (no NAT) Transmitting (no NAT) to 192.168.6.100:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-11c406cf;received=192.168.6.100 From: ;tag=e8409661b75ab035i0 To: "07803034440" ;tag=as465a4e16 Call-ID: 241cb33e679ce2a43c4beab66ee38386@192.168.6.6 CSeq: 102 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 23 18:22:28 DEBUG[4021]: channel.c:3398 ast_generic_bridge: Didn't get a frame from channel: SIP/707-2faa Jun 23 18:22:28 DEBUG[4021]: channel.c:3684 ast_channel_bridge: Bridge stops bridging channels Zap/1-1 and SIP/707-2faa Jun 23 18:22:28 DEBUG[4021]: channel.c:1493 ast_hangup: Hanging up channel 'SIP/707-2faa' Jun 23 18:22:28 DEBUG[4021]: chan_sip.c:3141 sip_hangup: Hangup call SIP/707-2faa, SIP callid 241cb33e679ce2a43c4beab66ee38386@192.168.6.6) Jun 23 18:22:28 DEBUG[4021]: chan_sip.c:3149 sip_hangup: update_call_counter(707) - decrement call limit counter on hangup Jun 23 18:22:28 DEBUG[4021]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 23 18:22:28 DEBUG[4021]: rtp.c:1313 ast_rtp_early_bridge: Channel 'Zap/1-1' has no RTP, not doing anything Jun 23 18:22:28 DEBUG[4021]: app_dial.c:1621 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jun 23 18:22:28 DEBUG[4021]: pbx.c:2258 __ast_pbx_run: Spawn extension (common,707,2) exited non-zero on 'Zap/1-1' -- Stopped music on hold on Zap/1-1 Jun 23 18:22:28 DEBUG[4021]: channel.c:2492 set_format: Set channel Zap/1-1 to write format alaw Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '07803034440' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '07803034440' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '707' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'common' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Zap/1-1' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/707-2faa' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Dial' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/707' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-23 18:22:04' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-23 18:22:04' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-23 18:22:28' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '24' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '24' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1151083324.0' Jun 23 18:22:28 DEBUG[4021]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 23 18:22:28 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 707 Jun 23 18:22:28 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/707 - state 1 (Not in use) Jun 23 18:22:28 DEBUG[4031]: app_queue.c:529 changethread: Device 'SIP/707' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 23 18:22:29 DEBUG[4021]: channel.c:1493 ast_hangup: Hanging up channel 'Zap/1-1' Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:2346 zt_hangup: zt_hangup(Zap/1-1) Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:2888 zt_setoption: Set option AUDIO MODE, value: ON(1) on Zap/1-1 Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:2379 zt_hangup: Hangup: channel: 1 index = 0, normal = 14, callwait = -1, thirdcall = -1 Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:2527 zt_hangup: Not yet hungup... Calling hangup once with icause, and clearing call Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:1420 zt_disable_ec: disabled echo cancellation on channel 1 Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:2805 zt_setoption: Set option TDD MODE, value: OFF(0) on Zap/1-1 Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:1357 update_conf: Updated conferencing on 1, with 0 conference users Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:2884 zt_setoption: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 Jun 23 18:22:29 DEBUG[4021]: chan_zap.c:1420 zt_disable_ec: disabled echo cancellation on channel 1 -- Hungup 'Zap/1-1' Jun 23 18:22:29 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for Zap/1 - state 0 (Unknown) Jun 23 18:22:29 DEBUG[4032]: app_queue.c:529 changethread: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. <-- SIP read from 192.168.6.100:5060: INVITE sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-9e95448 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 103 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="86b2a5d4086ba3424a26bdd7b5138072" Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 226 Content-Type: application/sdp v=0 o=- 561740 561740 IN IP4 192.168.6.100 s=- c=IN IP4 0.0.0.0 t=0 0 m=audio 16446 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendonly Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:747@192.168.6.6 SIP/2.0 (34) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-9e95448 (58) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=as0576aac0 (40) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 103 INVITE (16) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="86b2a5d4086ba3424a26bdd7b5138072" (160) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: "707 Test" (48) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Expires: 30 (11) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Length: 226 (19) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: Content-Type: application/sdp (29) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 561740 561740 IN IP4 192.168.6.100 (38) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 0.0.0.0 (16) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16446 RTP/AVP 0 8 101 (29) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendonly (10) --- (13 headers 12 lines)--- Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.100 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 0.0.0.0:16446 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/707-f997 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:16446 Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 23 18:22:29 DEBUG[4006]: 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/747-8ddb Jun 23 18:22:29 DEBUG[4006]: channel.c:1793 ast_settimeout: Scheduling timer at 160 sample intervals Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call ad786ed-e6079dcf@192.168.6.100 Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-f997: New call is UP.... Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.6.6 port 19276 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 23 18:22:29 DEBUG[4006]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.6.100:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-9e95448;received=192.168.6.100 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 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: 271 v=0 o=root 3990 3991 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 19276 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 23 18:22:29 DEBUG[4006]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #25 Really destroying SIP dialog '241cb33e679ce2a43c4beab66ee38386@192.168.6.6' Method: BYE Jun 23 18:22:29 DEBUG[4026]: channel.c:2073 __ast_read: Generator got voice, switching to phase locked mode Jun 23 18:22:29 DEBUG[4026]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 23 18:22:29 DEBUG[4026]: channel.c:2492 set_format: Set channel SIP/747-8ddb to write format ulaw Jun 23 18:22:29 DEBUG[4026]: res_musiconhold.c:251 ast_moh_files_next: SIP/747-8ddb Opened file 8 '/var/lib/asterisk/sounds/custom/moh/track18' <-- SIP read from 192.168.6.100:5060: ACK sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-40d73d25 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 103 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="4ea677cbf469d5fc65dc17537cb2df8c" Contact: "707 Test" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: ACK sip:747@192.168.6.6 SIP/2.0 (31) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-40d73d25 (59) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=as0576aac0 (40) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 103 ACK (13) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="4ea677cbf469d5fc65dc17537cb2df8c" (160) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: "707 Test" (48) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #25 Jun 23 18:22:29 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on 'ad786ed-e6079dcf@192.168.6.100' of Response 103: Match Not Found <-- SIP read from 192.168.6.100:5060: INVITE sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5ba4a408 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 104 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="86b2a5d4086ba3424a26bdd7b5138072" Contact: "707 Test" Expires: 30 User-Agent: Sipura/SPA941-4.1.8 Content-Length: 232 Content-Type: application/sdp v=0 o=- 562282 562282 IN IP4 192.168.6.100 s=- c=IN IP4 192.168.6.100 t=0 0 m=audio 16446 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: INVITE sip:747@192.168.6.6 SIP/2.0 (34) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5ba4a408 (59) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=as0576aac0 (40) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 104 INVITE (16) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="86b2a5d4086ba3424a26bdd7b5138072" (160) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: "707 Test" (48) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: Expires: 30 (11) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: Content-Length: 232 (19) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 12: Content-Type: application/sdp (29) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 13: (0) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: v=0 (3) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: o=- 562282 562282 IN IP4 192.168.6.100 (38) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: s=- (3) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: c=IN IP4 192.168.6.100 (22) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: t=0 0 (5) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: m=audio 16446 RTP/AVP 0 8 101 (29) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:0 PCMU/8000 (20) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:8 PCMA/8000 (20) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=rtpmap:101 telephone-event/8000 (33) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=fmtp:101 0-15 (15) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=ptime:30 (10) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4339 parse_request: Line: a=sendrecv (10) --- (13 headers 12 lines)--- Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received INVITE (5) - Command in SIP INVITE Sending to 192.168.6.100 : 5060 (no NAT) Found RTP audio format 0 Found RTP audio format 8 Found RTP audio format 101 Peer audio RTP is at port 192.168.6.100:16446 Found description format PCMU for ID 0 Found description format PCMA for ID 8 Found description format telephone-event for ID 101 Got unsupported a:fmtp in SDP offer Got unsupported a:ptime in SDP offer Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4817 process_sdp: T38 state changed to 0 on channel SIP/707-f997 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.6.100:16446 Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4887 process_sdp: We're settling with these formats: 0xe (gsm|ulaw|alaw) Jun 23 18:22:34 DEBUG[4006]: 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/747-8ddb Jun 23 18:22:34 DEBUG[4006]: channel.c:2492 set_format: Set channel SIP/747-8ddb to write format ulaw Jun 23 18:22:34 DEBUG[4006]: channel.c:1793 ast_settimeout: Scheduling timer at 0 sample intervals Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:12830 handle_request_invite: Got a SIP re-invite for call ad786ed-e6079dcf@192.168.6.100 Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:12919 handle_request_invite: SIP/707-f997: New call is UP.... Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:5783 add_sdp: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:5784 add_sdp: ** Our prefcodec: 0x0 (nothing) Audio is at 192.168.6.6 port 19276 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 23 18:22:34 DEBUG[4006]: chan_sip.c:5934 add_sdp: -- Done with adding codecs to SDP Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:5973 add_sdp: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) Reliably Transmitting (no NAT) to 192.168.6.100:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-5ba4a408;received=192.168.6.100 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 104 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 271 v=0 o=root 3990 3992 IN IP4 192.168.6.6 s=session c=IN IP4 192.168.6.6 t=0 0 m=audio 19276 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 23 18:22:34 DEBUG[4006]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #26 <-- SIP read from 192.168.6.100:5060: ACK sip:747@192.168.6.6 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-d6ee3283 From: "707 Test" ;tag=4122a4559a24df87o0 To: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 104 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="4ea677cbf469d5fc65dc17537cb2df8c" Contact: "707 Test" User-Agent: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: ACK sip:747@192.168.6.6 SIP/2.0 (31) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.100:5060;branch=z9hG4bK-d6ee3283 (59) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: "707 Test" ;tag=4122a4559a24df87o0 (61) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: ;tag=as0576aac0 (40) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: CSeq: 104 ACK (13) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Max-Forwards: 70 (16) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Proxy-Authorization: Digest username="707",realm="asterisk",nonce="17ee85fb",uri="sip:747@192.168.6.6",algorithm=MD5,response="4ea677cbf469d5fc65dc17537cb2df8c" (160) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Contact: "707 Test" (48) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: User-Agent: Sipura/SPA941-4.1.8 (31) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 10: Content-Length: 0 (17) Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 11: (0) --- (11 headers 0 lines)--- Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received ACK (6) - Command in SIP ACK Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #26 Jun 23 18:22:34 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on 'ad786ed-e6079dcf@192.168.6.100' of Response 104: Match Not Found <-- SIP read from 192.168.6.159:50515: BYE sip:707@192.168.6.6:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.159:5060;branch=z9hG4bK6c312cbc From: ;tag=00059bf197bc000a42388b02-57441a6e To: "Test 707" ;tag=as222635ed Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 Date: Fri, 23 Jun 2006 17:22:41 GMT CSeq: 101 BYE User-Agent: CSCO/7 Content-Length: 0 Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: BYE sip:707@192.168.6.6:5060 SIP/2.0 (36) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: Via: SIP/2.0/UDP 192.168.6.159:5060;branch=z9hG4bK6c312cbc (58) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=00059bf197bc000a42388b02-57441a6e (72) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: To: "Test 707" ;tag=as222635ed (51) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 (53) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Date: Fri, 23 Jun 2006 17:22:41 GMT (35) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: CSeq: 101 BYE (13) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: User-Agent: CSCO/7 (18) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: Content-Length: 0 (17) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 9: (0) --- (9 headers 0 lines)--- Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:13965 handle_request: **** Received BYE (8) - Command in SIP BYE Sending to 192.168.6.159 : 5060 (no NAT) Transmitting (no NAT) to 192.168.6.159:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.6.159:5060;branch=z9hG4bK6c312cbc;received=192.168.6.159 From: ;tag=00059bf197bc000a42388b02-57441a6e To: "Test 707" ;tag=as222635ed Call-ID: 00fb5bc2314b80135327444a639f4bfc@192.168.6.6 CSeq: 101 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 --- Jun 23 18:22:41 DEBUG[4026]: channel.c:3398 ast_generic_bridge: Didn't get a frame from channel: SIP/747-8ddb Jun 23 18:22:41 DEBUG[4026]: channel.c:3684 ast_channel_bridge: Bridge stops bridging channels SIP/707-f997 and SIP/747-8ddb Jun 23 18:22:41 DEBUG[4026]: channel.c:1493 ast_hangup: Hanging up channel 'SIP/747-8ddb' Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:3141 sip_hangup: Hangup call SIP/747-8ddb, SIP callid 00fb5bc2314b80135327444a639f4bfc@192.168.6.6) Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:3149 sip_hangup: update_call_counter(747) - decrement call limit counter on hangup Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:2841 update_call_counter: Updating call counter for outgoing call Jun 23 18:22:41 DEBUG[4026]: rtp.c:1321 ast_rtp_early_bridge: Channel '' has no RTP, not doing anything Jun 23 18:22:41 DEBUG[4026]: app_dial.c:1621 dial_exec_full: Exiting with DIALSTATUS=ANSWER. Jun 23 18:22:41 DEBUG[4026]: pbx.c:2258 __ast_pbx_run: Spawn extension (from-sip,747,2) exited non-zero on 'SIP/707-f997' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1675 pbx_extension_helper: Launching 'NoOp' -- Executing [h@from-sip:1] NoOp("SIP/707-f997", "Reached Hangup Extension") in new stack Jun 23 18:22:41 DEBUG[4026]: pbx.c:1675 pbx_extension_helper: Launching 'Hangup' -- Executing [h@from-sip:2] Hangup("SIP/707-f997", "") in new stack Jun 23 18:22:41 DEBUG[4026]: pbx.c:2378 __ast_pbx_run: Spawn extension (from-sip,h,2) exited non-zero on 'SIP/707-f997' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '"Test 707" <707>' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '707' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '747' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'from-sip' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/707-f997' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'SIP/747-8ddb' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'Hangup' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-23 18:22:16' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-23 18:22:16' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '2006-06-23 18:22:41' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '25' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '25' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '1151083336.2' Jun 23 18:22:41 DEBUG[4026]: pbx.c:1529 pbx_substitute_variables_helper_full: Function result is '' Jun 23 18:22:41 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 747 Jun 23 18:22:41 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/747 - state 1 (Not in use) Jun 23 18:22:41 DEBUG[4033]: app_queue.c:529 changethread: Device 'SIP/747' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jun 23 18:22:41 DEBUG[4026]: channel.c:1493 ast_hangup: Hanging up channel 'SIP/707-f997' Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:3141 sip_hangup: Hangup call SIP/707-f997, SIP callid ad786ed-e6079dcf@192.168.6.100) Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:3149 sip_hangup: update_call_counter(707) - decrement call limit counter on hangup Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:2841 update_call_counter: Updating call counter for incoming call Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:5318 reqprep: Strict routing enforced for session ad786ed-e6079dcf@192.168.6.100 set_destination: Parsing for address/port to send to set_destination: set destination to 192.168.6.100, port 5060 Reliably Transmitting (no NAT) to 192.168.6.100:5060: BYE sip:707@192.168.6.100:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK35e27029;rport From: ;tag=as0576aac0 To: "707 Test" ;tag=4122a4559a24df87o0 Contact: Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Jun 23 18:22:41 DEBUG[4026]: chan_sip.c:1881 __sip_reliable_xmit: *** SIP TIMER: Initalizing retransmit timer on packet: Id #28 Jun 23 18:22:41 DEBUG[3994]: chan_sip.c:14532 sip_devicestate: Checking device state for peer 707 Jun 23 18:22:41 DEBUG[3994]: devicestate.c:189 do_state_change: Changing state for SIP/707 - state 1 (Not in use) Jun 23 18:22:41 DEBUG[4034]: app_queue.c:529 changethread: Device 'SIP/707' 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.6.100:5060: SIP/2.0 200 OK To: "707 Test" ;tag=4122a4559a24df87o0 From: ;tag=as0576aac0 Call-ID: ad786ed-e6079dcf@192.168.6.100 CSeq: 102 BYE Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK35e27029 Server: Sipura/SPA941-4.1.8 Content-Length: 0 Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 0: SIP/2.0 200 OK (14) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 1: To: "707 Test" ;tag=4122a4559a24df87o0 (59) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 2: From: ;tag=as0576aac0 (42) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 3: Call-ID: ad786ed-e6079dcf@192.168.6.100 (39) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 4: CSeq: 102 BYE (13) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 5: Via: SIP/2.0/UDP 192.168.6.6:5060;branch=z9hG4bK35e27029 (56) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 6: Server: Sipura/SPA941-4.1.8 (27) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 7: Content-Length: 0 (17) Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:4307 parse_request: Header 8: (0) --- (8 headers 0 lines)--- Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:1974 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #28 Jun 23 18:22:41 DEBUG[4006]: chan_sip.c:1984 __sip_ack: Stopping retransmission on 'ad786ed-e6079dcf@192.168.6.100' of Request 102: Match Not Found SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog '00fb5bc2314b80135327444a639f4bfc@192.168.6.6' Method: BYE Really destroying SIP dialog 'ad786ed-e6079dcf@192.168.6.100' Method: ACK stop now Beginning asterisk shutdown.... Executing last minute cleanups == Destroying musiconhold processes Asterisk cleanly ending (0). [root@foxtrot asterisk]#