[SOLVED] Trigger page on incoming CALL

system · April 2, 2012, 4:03pm

Hello,

I have read a lot of web pages before posting but I need help trying to understand what is missing

Nothing happens with my DIALPLAN, the PHP script is not executed… any ideas?

NOTE: XXXXXXX is my LocalPhone.com ID number

Original code from LocalPhone.com in the file /etc/asterisk/extensions.conf

[localphone-in]
exten => XXXXXXX,1,Dial(SIP/sipphone,60,tr) ; phone must be registered
exten => XXXXXXX,2,Hangup

I have changed it to the following:
( /etc/asterisk/extensions.conf )

[localphone-in]
exten => XXXXXXX,1,AGI(/var/lib/asterisk/agi-bin/call.php)
exten => XXXXXXX,2,Dial(SIP/sipphone,60,tr) ; phone must be registered
exten => XXXXXXX,3,Hangup

PHP script creates a file if executed:

<?php
$file = "/var/lib/asterisk/agi-bin/logs/log_calls.txt";
$txt = "###";
file_put_contents($file, $txt);
echo "###\n";
?>

david55 · April 2, 2012, 4:24pm

There is no #! line. in-ulm.de/~mascheck/various/shebang/

Also, are you sure it is executable?

Technically it is broken, because it fails to read the initial parameters, but that shouldn’t invalidate the test.

system · April 2, 2012, 5:18pm

Hi David,

I have double checked again the permissions, the script and sub-folder are set to 777.

On the PHP file included #! at the begining, file as follows:

#!/usr/bin/php
<?php

Reading another webpage I have found a log file and executed it as tail -f /var/log/asterisk/messages to see log in realtime.

I have found that asterisk is also loading another file… /etc/asterisk/extensions.ael

So, I have disabled the other configuration in extensions.conf and used the extensions.ael, but does not work either…

I am really lost on this…

//
// If you wish to use AEL for your default context, remove it
// from extensions.conf (or change its name or comment it out)
// and then uncomment the one here.
//

context ael-default {

	s => {
		CALLERID(name)=HelloWorld;
		NoOp(My name is ${CALLERID(name)} !);

		System(/var/lib/asterisk/agi-bin/call.php);
		System(/usr/bin/php /var/lib/asterisk/agi-bin/call.php);
		AGI(/var/lib/asterisk/agi-bin/call.php);
		AGI(call.php);
		Hangup();
	};

// By default we include the demo.  In a production system, you
// probably don't want to have the demo there.

	//includes {
	//	ael-demo;
	//};

(...)

omid.mohajerani · April 2, 2012, 8:12pm

get sure if your php script work fine by running php call.php
put your asterisk log here when you are running AGI .
you dont need to write in extensions.ael . Its another method of writing dialplan based on Asterisk Extension Language .
you dont need to write the full path to agi folder . ( ofcourse it is not making any problem . ) you can just write AGI(call.php)

david55 · April 2, 2012, 8:58pm

777 is dangerous. Although I don’t think Asterisk is one of them, some programs would refuse to run world writeable scripts.

system · April 3, 2012, 11:50am

It runs fine by command
I have enable logs but AGI does not output any log (agi set debug on), I have also enable sip logs (sip set debug on) and can see the logs of the call
OK, I reverted the process and just use the extensions.conf, for me it is less confuse
OK

[quote=“omid.mohajerani”]get sure if your php script work fine by running php call.php
put your asterisk log here when you are running AGI .
you dont need to write in extensions.ael . Its another method of writing dialplan based on Asterisk Extension Language .
you dont need to write the full path to agi folder . ( ofcourse it is not making any problem . ) you can just write AGI(call.php)[/quote]

system · April 3, 2012, 11:54am

OK, when testing I usually do 777, I will have more attention on this detail : )

Actually, I am thinking to reinstall Asterisk, I have missed DADHI component.

Do you think it is relevant to install this? I am just using SIP to receive calls (I will not use outbound call) and can see the incoming call but not AGI logs.

ianplain · April 3, 2012, 1:10pm

Hi

I wouldn’t bother reinstalling to get dahdi that isn’t your problem

is Asterisk running as user and group asterisk ?

if it is, su to user asterisk and try running the php script .

Ian

omid.mohajerani · April 3, 2012, 1:31pm

I run the script in my asterisk box . It works without any problem . maybe you have forgotten one step. Just paste the console log when you dial the extension here .

system · April 4, 2012, 9:45am

I have uninstalled asterisk and installed again with yum and cleaned up code of the configuration files.
Followed the procedure on this page, but installed version 1.8
asterisk.org/downloads/yum
Created the repositories and installed with yum

yum update
yum install asterisk18 asterisk18-configs asterisk18-voicemail libpri

extensions.conf

; extensions.conf - the Asterisk dial plan
;
[general]
static=yes
writeprotect=no
clearglobalvars=no

[globals]
CONSOLE=Console/dsp				; Console interface for demo
;CONSOLE=DAHDI/1
;CONSOLE=Phone/phone0
IAXINFO=guest					; IAXtel username/password
;IAXINFO=myuser:mypass
TRUNK=DAHDI/G2					; Trunk interface

TRUNKMSD=1					; MSD digits to strip (usually 1 or 0)[default]

include => localphone-in

[localphone-in]
exten => 2300541,1,AGI(call.php)
exten => 2300541,2,Dial(SIP/sipphone,60,tr)       ; phone must be registered
exten => 2300541,3,Hangup

sip.conf

[general]
port      = 5060
bindaddr  = 0.0.0.0
qualify   = no
disable   = all
allow     = alaw
allow     = ulaw
dtmfmode  = rfc2833
srvlookup = yes

register => 2300541:PASSWORD@localphone.com/2300541

context=default                 ; Default context for incoming calls
allowoverlap=no                 ; Disable overlap dialing support. (Default is yes)
udpbindaddr=0.0.0.0             ; IP address to bind UDP listen socket to (0.0.0.0 binds to all)
                                ; Optionally add a port number, 192.168.1.1:5062 (default is port 5060)

tcpenable=no                    ; Enable server for incoming TCP connections (default is no)
tcpbindaddr=0.0.0.0             ; IP address for TCP server to bind to (0.0.0.0 binds to all interfaces)
                                ; Optionally add a port number, 192.168.1.1:5062 (default is port 5060)

;tlsenable=no                   ; Enable server for incoming TLS (secure) connections (default is no)
;tlsbindaddr=0.0.0.0            ; IP address for TLS server to bind to (0.0.0.0) binds to all interfaces)
                                ; Optionally add a port number, 192.168.1.1:5063 (default is port 5061)
                                ; Remember that the IP address must match the common name (hostname) in the
                                ; certificate, so you don't want to bind a TLS socket to multiple IP addresses.
                                ; For details how to construct a certificate for SIP see 
                                ; http://tools.ietf.org/html/draft-ietf-sip-domain-certs

[localphone]
type        = friend
insecure    = very
;nat         = no
canreinvite = no
authuser    = 2300541
username    = 2300541
fromuser    = 2300541
fromdomain  = localphone.com
secret      = PASSWORD
host        = localphone.com
dtmfmode    = rfc2833
context     = localphone-in     ; extensions.conf context for inbound calls
disallow    = all
allow       = ulaw
allow       = alaw

qualify     = yes
nat         = yes

Changed permissions to 755 on the directory and files in /var/lib/asterisk/agi-bin
Changed group and user to asterisk on the directory and files in /var/lib/asterisk/agi-bin
Tried su asterisk and ran the PHP script without any problem.
Calling to the phone in the format +351 123123123, I can see the incoming calls in the Asterisk console.
I still can’t see any log from AGI, I dont know how to execute them… I will copy/paste full console logs later.

How can I simulate the execution of an AGI script from the Asterisk console?

ianplain · April 4, 2012, 9:50am

Hi

As is said over and over again

the most important things are:

I still can’t see any log from AGI, I dont know how to execute them… I will copy/paste full console logs later.

so we can see whats happening and make sense of it

system · April 4, 2012, 11:53am

Sorry for not sending logs earlier.
But today at the time or writing I could not post logs because I did not had them.
I needed first, to read, understand, read again, and try, try, try… to see what I am doing wrong… but Asterisk is really hard to get it work

System specification:

Operating system 	CentOS Linux 5.8
Kernel and CPU 	Linux 2.6.34.6-xxxx-grs-ipv6-64 on x86_64 
CPU load averages 	0.34 (1 min) 0.26 (5 mins) 0.19 (15 mins)
Running processes 	470
Real memory 	11.75 GB total, 2.50 GB used

Simpler file to test execution /var/lib/asterisk/agi-bin/call.sh

#! /bin/bash
echo "1" > /var/lib/asterisk/agi-bin/log_bash.txt

extensions.conf

; extensions.conf - the Asterisk dial plan
;
[general]
static=yes
writeprotect=no
clearglobalvars=no

[globals]
CONSOLE=Console/dsp				; Console interface for demo
;CONSOLE=DAHDI/1
;CONSOLE=Phone/phone0
IAXINFO=guest					; IAXtel username/password
;IAXINFO=myuser:mypass
TRUNK=DAHDI/G2					; Trunk interface
TRUNKMSD=1					; MSD digits to strip (usually 1 or 0)[default]

include => localphone-in


[localphone-in]
exten => 2300541,1,AGI(call.sh)
exten => 2300541,2,Dial(SIP/sipphone,60,tr)       ; phone must be registered
exten => 2300541,3,Hangup

logger.conf

; (...)
debug => debug
;console => notice,warning,error
console => notice,warning,error,debug
messages => notice,warning,error
full => notice,warning,error,debug,verbose,dtmf,fax
; (...)

sip show peers

Name/username              Host                                    Dyn Forcerport ACL Port     Status
localphone/2300541         94.75.247.45                                 N      5060     OK (11 ms)
1 sip peers [Monitored: 1 online, 0 offline Unmonitored: 0 online, 0 offline]

*CLI> sip set debug on
SIP Debugging enabled
*CLI> agi set debug on
AGI Debugging Enabled

Log is incomplete because it is huge…

I did this command to show logging, if there is a better one let me know.
/usr/sbin/asterisk -vvvvvv -g -dddddd -c

SSH Putty session log.

(...)

 == Registered custom function 'QUEUE_WAITING_COUNT'
  == Registered custom function 'QUEUE_MEMBER_PENALTY'
 app_queue.so => (True Call Queueing)
  == Parsing '/etc/asterisk/cli_permissions.conf': [Apr  4 12:28:49] DEBUG[16331]: config.c:1490 config_text_file_load: Parsing /etc/asterisk/cli_permissions.conf
  == Found
Asterisk Ready.
  == Parsing '/etc/asterisk/cli.conf': [Apr  4 12:28:49] DEBUG[16331]: config.c:1490 config_text_file_load: Parsing /etc/asterisk/cli.conf
  == Found
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
       > doing dnsmgr_lookup for 'localphone.com'
       > ast_get_srv: SRV lookup for '_sip._udp.localphone.com' mapped to host proxy.localphone.com, port 5060
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'proxy.localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'proxy.localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS - REGISTER (No RTP)
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3016 registry_addref: SIP Registry localphone.com: refcount now 3
[Apr  4 12:28:49] DEBUG[16360]: acl.c:725 ast_ouraddrfor: For destination '94.75.247.45', our source address is 'SERVER-IP-ADDRESS'.
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address SERVER-IP-ADDRESS:5060
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3016 registry_addref: SIP Registry localphone.com: refcount now 4
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:12861 transmit_register: Scheduled a registration timeout for localphone.com id  #6 
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3054 initialize_initreq: Initializing initreq for method REGISTER - callid 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:12937 transmit_register: REGISTER attempt 1 to 2300541@localphone.com
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3325 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 94.75.247.45:5060
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3008 registry_unref: SIP Registry localphone.com: refcount now 3
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:7835 find_call: = Looking for  Call ID: 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS (Checking To) --From tag as7e5fcb79 --To-tag 9399de1ef8c379d4c914a855a096e8ba.44e8  
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:4011 __sip_ack: Stopping retransmission on '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS' of Request 102: Match Found
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
       > doing dnsmgr_lookup for 'localphone.com'
       > ast_get_srv: SRV lookup for '_sip._udp.localphone.com' mapped to host proxy.localphone.com, port 5060
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'proxy.localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'proxy.localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting 'localphone.com' into...
[Apr  4 12:28:49] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host 'localphone.com' and port ''.
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3052 initialize_initreq: Initializing already initialized SIP dialog 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS (presumably reinvite)
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:12937 transmit_register: REGISTER attempt 2 to 2300541@localphone.com
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3325 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 94.75.247.45:5060
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:7835 find_call: = Looking for  Call ID: 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS (Checking To) --From tag as58da7dd1 --To-tag 9399de1ef8c379d4c914a855a096e8ba.cdfb  
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:4011 __sip_ack: Stopping retransmission on '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS' of Request 103: Match Found
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:20096 handle_response_register: Registration successful
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:20098 handle_response_register: Cancelling timeout 6
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3008 registry_unref: SIP Registry localphone.com: refcount now 2
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3008 registry_unref: SIP Registry localphone.com: refcount now 1
[Apr  4 12:28:49] DEBUG[16360]: chan_sip.c:3016 registry_addref: SIP Registry localphone.com: refcount now 2
[Apr  4 12:29:21] DEBUG[16360]: chan_sip.c:3869 __sip_autodestruct: Auto destroying SIP dialog '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS'
[Apr  4 12:29:21] DEBUG[16360]: chan_sip.c:5898 sip_destroy: Destroying SIP dialog 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS
sip set debug on

SIP Debugging enabled
*CLI> sip set debug on[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for 747e02ef5a1e030a1f359d040f769a56@SERVER-IP-ADDRESS:0 - OPTIONS (No RTP)
[Apr  4 12:29:49] DEBUG[16360]: acl.c:725 ast_ouraddrfor: For destination '94.75.247.45', our source address is 'SERVER-IP-ADDRESS'.
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address SERVER-IP-ADDRESS:5060
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:3054 initialize_initreq: Initializing initreq for method OPTIONS - callid 27db99ce080218a63259c70751d0d259@SERVER-IP-ADDRESS:5060
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  0 [ 34]: OPTIONS sip:localphone.com SIP/2.0
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  1 [ 64]: Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK28c11120;rport
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  3 [ 60]: From: "asterisk" <sip:asterisk@SERVER-IP-ADDRESS>;tag=as657a3bfc
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  4 [ 24]: To: <sip:localphone.com>
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  5 [ 42]: Contact: <sip:asterisk@SERVER-IP-ADDRESS:5060>
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  6 [ 60]: Call-ID: 27db99ce080218a63259c70751d0d259@SERVER-IP-ADDRESS:5060
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  8 [ 32]: User-Agent: Asterisk PBX 1.8.7.0
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  9 [ 35]: Date: Wed, 04 Apr 2012 11:29:49 GMT
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Apr  4 12:29:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 94.75.247.45:5060:
OPTIONS sip:localphone.com SIP/2.0

Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK28c11120;rport

Max-Forwards: 70

From: "asterisk" <sip:asterisk@SERVER-IP-ADDRESS>;tag=as657a3bfc

To: <sip:localphone.com>

Contact: <sip:asterisk@SERVER-IP-ADDRESS:5060>

Call-ID: 27db99ce080218a63259c70751d0d259@SERVER-IP-ADDRESS:5060

CSeq: 102 OPTIONS

User-Agent: Asterisk PBX 1.8.7.0

Date: Wed, 04 Apr 2012 11:29:49 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Length: 0




---

(...)

[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3782 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #33
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3325 __sip_xmit: Trying to put 'REGISTER si' onto UDP socket destined for 94.75.247.45:5060
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3008 registry_unref: SIP Registry localphone.com: refcount now 3

<--- SIP read from UDP:94.75.247.45:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK74ea07c0;rport=5060
From: <sip:2300541@localphone.com>;tag=as40bec320
To: <sip:2300541@localphone.com>;tag=9399de1ef8c379d4c914a855a096e8ba.6d0e
Call-ID: 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS
CSeq: 105 REGISTER
Contact: <sip:2300541@SERVER-IP-ADDRESS:5060>;expires=120
Server: OpenSER (1.2.2-notls (i386/linux))
Content-Length: 0

<------------->
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  0 [ 14]: SIP/2.0 200 OK
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  1 [ 69]: Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK74ea07c0;rport=5060
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  2 [ 49]: From: <sip:2300541@localphone.com>;tag=as40bec320
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  3 [ 74]: To: <sip:2300541@localphone.com>;tag=9399de1ef8c379d4c914a855a096e8ba.6d0e
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  4 [ 55]: Call-ID: 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  5 [ 18]: CSeq: 105 REGISTER
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  6 [ 53]: Contact: <sip:2300541@SERVER-IP-ADDRESS:5060>;expires=120
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  7 [ 42]: Server: OpenSER (1.2.2-notls (i386/linux))
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  8 [ 17]: Content-Length: 0
--- (9 headers 0 lines) ---
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:7835 find_call: = Looking for  Call ID: 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS (Checking To) --From tag as40bec320 --To-tag 9399de1ef8c379d4c914a855a096e8ba.6d0e  
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3978 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #33
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:4011 __sip_ack: Stopping retransmission on '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS' of Request 105: Match Found
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:20096 handle_response_register: Registration successful
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:20098 handle_response_register: Cancelling timeout 32
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3008 registry_unref: SIP Registry localphone.com: refcount now 2
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3008 registry_unref: SIP Registry localphone.com: refcount now 1
Scheduling destruction of SIP dialog '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS' in 32000 ms (Method: REGISTER)
[Apr  4 12:32:19] NOTICE[16360]: chan_sip.c:20148 handle_response_register: Outbound Registration: Expiry for localphone.com is 120 sec (Scheduling reregistration in 105 s)
[Apr  4 12:32:19] DEBUG[16360]: chan_sip.c:3016 registry_addref: SIP Registry localphone.com: refcount now 2

<--- SIP read from UDP:94.75.247.45:5060 --->
INVITE sip:2300541@SERVER-IP-ADDRESS:5060 SIP/2.0
Record-Route: <sip:94.75.247.45;lr=on;ftag=72164>
Record-Route: <sip:95.211.119.240;lr;ftag=72164;did=3e2.17d03471>
Call-ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
CSeq: 102 INVITE
From: "MY-PHONE-NUMBER" <sip:MY-PHONE-NUMBER@voxbone.com>;tag=72164
To: <sip:LOCALPHONE-CALL-NUMBER@95.211.119.240>
Via: SIP/2.0/UDP 94.75.247.45;branch=z9hG4bK3b19.a2827f4.0
Via: SIP/2.0/UDP 95.211.119.240;rport=5060;branch=z9hG4bK3b19.0b9602c4.0
Via: SIP/2.0/UDP 81.201.84.45:5060;branch=z9hG4bKaa697bb4584bb603fde0b317080d39e8
Max-Forwards: 12
Content-Type: application/sdp
Contact: <sip:MY-PHONE-NUMBER@81.201.84.45:5060;transport=udp>
User-Agent: Vox Callcontrol
Content-Length: 311

v=0
o=root 25983 25983 IN IP4 81.201.84.33
s=session
c=IN IP4 81.201.84.33
t=0 0
m=audio 10244 RTP/AVP 8 0 18 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  0 [ 45]: INVITE sip:2300541@SERVER-IP-ADDRESS:5060 SIP/2.0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  1 [ 49]: Record-Route: <sip:94.75.247.45;lr=on;ftag=72164>
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  2 [ 65]: Record-Route: <sip:95.211.119.240;lr;ftag=72164;did=3e2.17d03471>
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  3 [ 48]: Call-ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  4 [ 16]: CSeq: 102 INVITE
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  5 [ 61]: From: "MY-PHONE-NUMBER" <sip:MY-PHONE-NUMBER@voxbone.com>;tag=72164
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  6 [ 37]: To: <sip:LOCALPHONE-CALL-NUMBER@95.211.119.240>
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  7 [ 58]: Via: SIP/2.0/UDP 94.75.247.45;branch=z9hG4bK3b19.a2827f4.0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  8 [ 72]: Via: SIP/2.0/UDP 95.211.119.240;rport=5060;branch=z9hG4bK3b19.0b9602c4.0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  9 [ 81]: Via: SIP/2.0/UDP 81.201.84.45:5060;branch=z9hG4bKaa697bb4584bb603fde0b317080d39e8
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 10 [ 16]: Max-Forwards: 12
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 11 [ 29]: Content-Type: application/sdp
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 12 [ 59]: Contact: <sip:MY-PHONE-NUMBER@81.201.84.45:5060;transport=udp>
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 13 [ 27]: User-Agent: Vox Callcontrol
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 14 [ 19]: Content-Length: 311
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 15 [  0]: 
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  0 [  3]: v=0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  1 [ 38]: o=root 25983 25983 IN IP4 81.201.84.33
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  2 [  9]: s=session
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  3 [ 21]: c=IN IP4 81.201.84.33
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  4 [  5]: t=0 0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  5 [ 32]: m=audio 10244 RTP/AVP 8 0 18 101
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  6 [ 20]: a=rtpmap:8 PCMA/8000
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  7 [ 20]: a=rtpmap:0 PCMU/8000
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  8 [ 21]: a=rtpmap:18 G729/8000
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body  9 [ 19]: a=fmtp:18 annexb=no
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body 10 [ 33]: a=rtpmap:101 telephone-event/8000
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body 11 [ 15]: a=fmtp:101 0-16
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body 12 [ 25]: a=silenceSupp:off - - - -
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:    Body 13 [ 10]: a=ptime:20
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8279 parse_request:    Body 14 [ 10]: a=sendrecv
--- (15 headers 15 lines) ---
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:7835 find_call: = Looking for  Call ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45 (Checking From) --From tag 72164 --To-tag   
[Apr  4 12:32:46] DEBUG[16360]: acl.c:725 ast_ouraddrfor: For destination '94.75.247.45', our source address is 'SERVER-IP-ADDRESS'.
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address SERVER-IP-ADDRESS:5060
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45 - INVITE (No RTP)
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:24471 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE
[Apr  4 12:32:46] DEBUG[16360]: netsock2.c:134 ast_sockaddr_split_hostport: Splitting '94.75.247.45' into...
[Apr  4 12:32:46] DEBUG[16360]: netsock2.c:188 ast_sockaddr_split_hostport: ...host '94.75.247.45' and port ''.
Sending to 94.75.247.45:5060 (no NAT)
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:21895 handle_request_invite: Initializing initreq for method INVITE - callid W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
Using INVITE request as basis request - W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
Found peer 'localphone' for 'MY-PHONE-NUMBER' from 94.75.247.45:5060

<--- Reliably Transmitting (NAT) to 94.75.247.45:5060 --->
SIP/2.0 401 Unauthorized

Via: SIP/2.0/UDP 94.75.247.45;branch=z9hG4bK3b19.a2827f4.0;received=94.75.247.45;rport=5060

Via: SIP/2.0/UDP 95.211.119.240;rport=5060;branch=z9hG4bK3b19.0b9602c4.0

Via: SIP/2.0/UDP 81.201.84.45:5060;branch=z9hG4bKaa697bb4584bb603fde0b317080d39e8

From: "MY-PHONE-NUMBER" <sip:MY-PHONE-NUMBER@voxbone.com>;tag=72164

To: <sip:LOCALPHONE-CALL-NUMBER@95.211.119.240>;tag=as5ffb73ca

Call-ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45

CSeq: 102 INVITE

Server: Asterisk PBX 1.8.7.0

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="1ff30b98"

Content-Length: 0




<------------>
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:3782 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #36
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:3325 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 94.75.247.45:5060
Scheduling destruction of SIP dialog 'W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45' in 6400 ms (Method: INVITE)

<--- SIP read from UDP:94.75.247.45:5060 --->
ACK sip:2300541@SERVER-IP-ADDRESS:5060 SIP/2.0
Via: SIP/2.0/UDP 94.75.247.45;branch=z9hG4bK3b19.a2827f4.0
From: "MY-PHONE-NUMBER" <sip:MY-PHONE-NUMBER@voxbone.com>;tag=72164
Call-ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
To: <sip:LOCALPHONE-CALL-NUMBER@95.211.119.240>;tag=as5ffb73ca
CSeq: 102 ACK
User-Agent: OpenSER (1.2.2-notls (i386/linux))
Content-Length: 0

<------------->
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  0 [ 42]: ACK sip:2300541@SERVER-IP-ADDRESS:5060 SIP/2.0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  1 [ 58]: Via: SIP/2.0/UDP 94.75.247.45;branch=z9hG4bK3b19.a2827f4.0
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  2 [ 61]: From: "MY-PHONE-NUMBER" <sip:MY-PHONE-NUMBER@voxbone.com>;tag=72164
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  3 [ 48]: Call-ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  4 [ 52]: To: <sip:LOCALPHONE-CALL-NUMBER@95.211.119.240>;tag=as5ffb73ca
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  5 [ 13]: CSeq: 102 ACK
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  6 [ 46]: User-Agent: OpenSER (1.2.2-notls (i386/linux))
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  7 [ 17]: Content-Length: 0
--- (8 headers 0 lines) ---
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:7835 find_call: = Looking for  Call ID: W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45 (Checking From) --From tag 72164 --To-tag as5ffb73ca  
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:24471 handle_incoming: **** Received ACK (6) - Command in SIP ACK
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:3978 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #36
[Apr  4 12:32:46] DEBUG[16360]: chan_sip.c:4011 __sip_ack: Stopping retransmission on 'W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45' of Response 102: Match Found
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:7515 sip_alloc: Allocating new SIP dialog for 135768fe599244fd6a140112657d3c32@SERVER-IP-ADDRESS:0 - OPTIONS (No RTP)
[Apr  4 12:32:49] DEBUG[16360]: acl.c:725 ast_ouraddrfor: For destination '94.75.247.45', our source address is 'SERVER-IP-ADDRESS'.
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:3479 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address SERVER-IP-ADDRESS:5060
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:3054 initialize_initreq: Initializing initreq for method OPTIONS - callid 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  0 [ 34]: OPTIONS sip:localphone.com SIP/2.0
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  1 [ 64]: Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK39ba7342;rport
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  2 [ 16]: Max-Forwards: 70
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  3 [ 60]: From: "asterisk" <sip:asterisk@SERVER-IP-ADDRESS>;tag=as7267b707
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  4 [ 24]: To: <sip:localphone.com>
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  5 [ 42]: Contact: <sip:asterisk@SERVER-IP-ADDRESS:5060>
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  6 [ 60]: Call-ID: 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  7 [ 17]: CSeq: 102 OPTIONS
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  8 [ 32]: User-Agent: Asterisk PBX 1.8.7.0
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  9 [ 35]: Date: Wed, 04 Apr 2012 11:32:49 GMT
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header 11 [ 26]: Supported: replaces, timer
Reliably Transmitting (NAT) to 94.75.247.45:5060:
OPTIONS sip:localphone.com SIP/2.0

Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK39ba7342;rport

Max-Forwards: 70

From: "asterisk" <sip:asterisk@SERVER-IP-ADDRESS>;tag=as7267b707

To: <sip:localphone.com>

Contact: <sip:asterisk@SERVER-IP-ADDRESS:5060>

Call-ID: 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060

CSeq: 102 OPTIONS

User-Agent: Asterisk PBX 1.8.7.0

Date: Wed, 04 Apr 2012 11:32:49 GMT

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH

Supported: replaces, timer

Content-Length: 0




---
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:3782 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id  #38
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:3325 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 94.75.247.45:5060

<--- SIP read from UDP:94.75.247.45:5060 --->
SIP/2.0 200 ok
Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK39ba7342;rport=5060
From: "asterisk" <sip:asterisk@SERVER-IP-ADDRESS>;tag=as7267b707
To: <sip:localphone.com>;tag=9399de1ef8c379d4c914a855a096e8ba.b3d4
Call-ID: 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060
CSeq: 102 OPTIONS
Server: OpenSER (1.2.2-notls (i386/linux))
Content-Length: 0

<------------->
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  0 [ 14]: SIP/2.0 200 ok
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  1 [ 69]: Via: SIP/2.0/UDP SERVER-IP-ADDRESS:5060;branch=z9hG4bK39ba7342;rport=5060
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  2 [ 60]: From: "asterisk" <sip:asterisk@SERVER-IP-ADDRESS>;tag=as7267b707
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  3 [ 66]: To: <sip:localphone.com>;tag=9399de1ef8c379d4c914a855a096e8ba.b3d4
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  4 [ 60]: Call-ID: 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  5 [ 17]: CSeq: 102 OPTIONS
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  6 [ 42]: Server: OpenSER (1.2.2-notls (i386/linux))
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:8242 parse_request:  Header  7 [ 17]: Content-Length: 0
--- (8 headers 0 lines) ---
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:7835 find_call: = Looking for  Call ID: 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060 (Checking To) --From tag as7267b707 --To-tag 9399de1ef8c379d4c914a855a096e8ba.b3d4  
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:3978 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #38
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:4011 __sip_ack: Stopping retransmission on '0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060' of Request 102: Match Found
[Apr  4 12:32:49] DEBUG[16360]: chan_sip.c:5898 sip_destroy: Destroying SIP dialog 0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060
Really destroying SIP dialog '0c09b3850508e6a2543c7689608066b5@SERVER-IP-ADDRESS:5060' Method: OPTIONS
[Apr  4 12:32:51] DEBUG[16360]: chan_sip.c:3869 __sip_autodestruct: Auto destroying SIP dialog '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS'
[Apr  4 12:32:51] DEBUG[16360]: chan_sip.c:5898 sip_destroy: Destroying SIP dialog 5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS
Really destroying SIP dialog '5b140ba33b5b36f831fb63176eadd906@SERVER-IP-ADDRESS' Method: REGISTER
[Apr  4 12:32:52] DEBUG[16360]: chan_sip.c:3869 __sip_autodestruct: Auto destroying SIP dialog 'W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45'
[Apr  4 12:32:52] DEBUG[16360]: chan_sip.c:5898 sip_destroy: Destroying SIP dialog W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45
Really destroying SIP dialog 'W4DHQFTLLZEPZCNIRLPHAOE2B4@81.201.84.45' Method: ACK

ianplain · April 4, 2012, 9:31pm

yes
CLI> core set verbose 99
CLI> core set debug 10

then post the verbose output

also what does the full or messages log show ?

Ian

system · April 4, 2012, 10:26pm

I have found the issue! Thank you all for big patience!

The dial plan “localphone-in” is not being executed, I have subscribed another service from MessageNet and the dialplan was executed successfully including the AGI scripts!

Now I have a clear picture of the problem, just have to find the correct dialplan and/or SIP settings for LocalPhone.com

[localphone-in]
exten => _X.,1,Answer()
exten => _X.,2,SayNumber(123,f)
exten => _X.,3,System(/var/lib/asterisk/agi-bin/call.sh)
exten => _X.,4,System(/var/lib/asterisk/agi-bin/call.php)
exten => _X.,5,AGI(/var/lib/asterisk/agi-bin/call.sh)
exten => _X.,6,AGI(/var/lib/asterisk/agi-bin/call.php)
exten => _X.,100,Hangup

[messagenet-in]
exten => _X.,1,Answer()
exten => _X.,2,SayNumber(123,f)
exten => _X.,3,System(/var/lib/asterisk/agi-bin/call.sh)
exten => _X.,4,System(/var/lib/asterisk/agi-bin/call.php)
exten => _X.,5,AGI(/var/lib/asterisk/agi-bin/call.sh)
exten => _X.,6,AGI(/var/lib/asterisk/agi-bin/call.php)
exten => _X.,100,Hangup

system · April 4, 2012, 11:59pm

Continuing with tests

I have subscribed FlyNumber.com service for another DID number and works like a charm.

So the problem seems to be definitely the LocalPhone.com service that it not forwarding properly SIP communications.

FlyNumber.com configuration:
flynumber.com/asterisk-pbx-configuration

Virtual Phone Number:
351308xxxxxx

Forwarding - Voip:
SERVER-IP /308xxxxxx

extensions.conf
[from-fly]
exten => _X.,1,Answer()
exten => _X.,2,SayNumber(123,f)
exten => _X.,100,Hangup

ianplain · April 5, 2012, 9:30am

Hi

No th e problem is with your configuration, you just need to sort out what it is, if from the initial post you posted teh verbose output we could have seen what was happening.

system · April 10, 2012, 11:30pm

Well… I am very noob with Asterisk

This was my first Asterisk installation… I didnt even knew how to activate the logs but after reading a lot of forums, pages and getting help here I learned the basics and got it working.

The following line is wrong according to the instructions provided by Localphone ( help.localphone.com/voip/devices … e/asterisk )

insecure    = very

Working Localphone settings:

[localphone]
type        = friend
insecure    = invite,port
nat         = no
canreinvite = no
authuser    = LOCALPHONE-SIPID
username    = LOCALPHONE-SIPID
fromuser    = LOCALPHONE-SIPID
fromdomain  = localphone.com
secret      = LOCALPHONE-PASSWORD
host        = localphone.com
dtmfmode    = rfc2833
context     = localphone-in     ; extensions.conf context for inbound calls
disallow    = all
allow       = ulaw
allow       = alaw

qualify     = yes

Thank you all for the help provided

david55 · April 11, 2012, 6:54am

Actually, insecure=very is usually wrong in two ways. Not only has it been replaced, in the code, by insecure=port,invite, but it normally should have been insecure=invite (with no port). SIP providers tend to have taken the easy way out in suggesting configurations, and either opened up the security fully, or copied what others have done, rather than trying to understand what the option does.

They then failed to update their guidelines when the “very” value was deprecated and removed.

Topic		Replies	Views
Incoming calls and execution of PHP script Asterisk Support	0	265	June 11, 2007
Custom Dialplan Help Asterisk	4	677	August 4, 2016
Hangup handllers Asterisk Dialplan	5	124	June 6, 2024
Execute a script when SIP extension answers a call? Asterisk Support	8	3192	October 8, 2009
Execute a script in every extensions i have after hanging up every call Asterisk Dialplan	11	145	May 27, 2024

[SOLVED] Trigger page on incoming CALL

Related topics