Hi,
I’m attempting to get a cell phone to connect to a SIP phone. Luckily I have access to the complete system so I’m not limited to any other service provider 
I would appreciate some guidance on how to make the connection between them. My setup is the following…
CellPhone <–> BTS <–> BSC <–> MSC <-NETWORK-> ASTERISK-SIP-GATEWAY <–> SIP SOFTPHONE.
Thanks
Femto
What is the protocol on NETWORK? How is NETWORK connected to Asterisk?
Some more background would be useful as very few people would be licensed ot operate a BTS and want to do this.
Hi,
I’m fairly new to all this so please forgive the naive answers. The network is the office one. As far as I understand it, all the connections are via Ethernet onto the network. The BSC, MSC and Asterisk are ‘pingable’ from my PC.
The Wireshark log of the connection between my PC and SIP softphone shows the TCP, IPv4 and SIP protocols.
I agree that the BTS element is unusual as I work for a vendor. It’s the general principal of how a cell phone is able to communicate with an internal SIP phone I’m after.
Regards
Femto
Hi,
I’m getting closer! My soft SIP phone is now registered to Asterisk. I can ping my MSC (Mobile Switching Center) from Asterisk. I now need to route the SIP phone to the cell phone. Any ideas/hints on how to do this?
Cheers
Femto.
An MSC would normally use ISDN with the the SS7 mobile user part. You will need a suitable ISDN card, and cabling. You will probably need additional drivers or to support MUP, as I doubt that Asterisk currently supports MUP. The MSC might also use standard SS7, telephone user part, to interface to the fixed telephone network, in which case you would install the same hardware, but configure Asterisk for use with a normal ISDN backbone trunk. (I’m not sufficiently familiar with end user SS7 to know whether Asterisk supports this. I don’t believe that TUP is normally extended to the end user in the UK.)
Your reference to pings suggests that your MSC may have some, non-standard, VoIP landline side interface, in which case you will need to read its documentation in detail.
I am still concerned that you seem to have been let loose with equipment that has a potential for disrupting cellular communications in range of it without any understanding of how it works.
Hi,
Thanks for the detailed reply, much appreciated. Hopefully I can alleviate any fears as far as RF goes. In a previous life I was working within the DSP team and have written several device drivers for RF synthesiser chips. To me, that is the easy bit!
It’s true that a have a free reign over the rest of the equipment but it’s for me to setup and fix a bug which only occurs when a cell phone communicates with a SIP phone. My current difficulties are on how to get the various bits of equipment to communicate with each other. My test mobile has been camped on the BTS for over a week!
Most, if not all of the Asterisk examples appear to relate to intra SIP calls.
Cheers
Femto
Using the 1990s, UK, System X architecture, there would normally be a fixed network digital main switching unit and a DSSS concentrator between any mobile switching centre. and where one would normally put Asterisk. I’m not familiar with the current UK backbone architecture.
Hi,
I’m getting closer still! The cell phone is registered on the MSC and is aware of its presence. The SIP soft phone appears to be attempting to contact the MSC. Below is a section of the log as taken from the CLI. Any nudges gratefully received.
Cheers
Femto
Connected to Asterisk 1.6.2.11 currently running on localhost (pid = 3489)
localhostCLI>
Verbosity is at least 3
localhostCLI>
<— SIP read from UDP:172.28.3.149:5060 —>
<------------->
localhostCLI>
<— SIP read from UDP:172.28.3.149:5060 —>
SUBSCRIBE sip:4412490018@172.28.3.211 SIP/2.0
Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPjc554f632e97244438a3d0800a88cee43
Max-Forwards: 70
From: “Femto” sip:pg5@172.28.3.211;tag=28aa7a96d406496fbc26c848e2627d05
To: sip:4412490018@172.28.3.211
Contact: “Femto” sip:pg5@172.28.3.149:5060;ob
Call-ID: 0335c078e21a4fd89e9d3ac053690900
CSeq: 3625 SUBSCRIBE
Event: presence
Expires: 600
Supported: replaces, 100rel, timer, norefersub
Accept: application/pidf+xml, application/xpidf+xml
Allow-Events: presence, message-summary, refer
User-Agent: MicroSIP/3.1.7
Content-Length: 0
<------------->
— (15 headers 0 lines) —
Creating new subscription
Sending to 172.28.3.149 : 5060 (no NAT)
list_route: hop: sip:pg5@172.28.3.149:5060;ob
Found peer ‘pg5’ for ‘pg5’ from 172.28.3.149:5060
<— Transmitting (NAT) to 172.28.3.149:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.28.3.149:5060;branch=z9hG4bKPjc554f632e97244438a3d0800a88cee43;received=172.28.3.149;rport=5060
From: “Femto” sip:pg5@172.28.3.211;tag=28aa7a96d406496fbc26c848e2627d05
To: sip:4412490018@172.28.3.211;tag=as3fe876e3
Call-ID: 0335c078e21a4fd89e9d3ac053690900
CSeq: 3625 SUBSCRIBE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="032dad75"
Content-Length: 0
<------------>
Scheduling destruction of SIP dialog ‘0335c078e21a4fd89e9d3ac053690900’ in 6400 ms (Method: SUBSCRIBE)
localhostCLI>
<— SIP read from UDP:172.28.3.149:5060 —>
SUBSCRIBE sip:4412490018@172.28.3.211 SIP/2.0
Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPj88a12c9217484021866f300df85d6d77
Max-Forwards: 70
From: “Femto” sip:pg5@172.28.3.211;tag=28aa7a96d406496fbc26c848e2627d05
To: sip:4412490018@172.28.3.211
Contact: “Femto” sip:pg5@172.28.3.149:5060;ob
Call-ID: 0335c078e21a4fd89e9d3ac053690900
CSeq: 3626 SUBSCRIBE
Event: presence
Expires: 600
Supported: replaces, 100rel, timer, norefersub
Accept: application/pidf+xml, application/xpidf+xml
Allow-Events: presence, message-summary, refer
User-Agent: MicroSIP/3.1.7
Authorization: Digest username=“pg5”, realm=“asterisk”, nonce=“032dad75”, uri="sip:4412490018@172.28.3.211", response=“22cb8b8a90c398c4c4d17324cc98c151”, algorithm=MD5
Content-Length: 0
<------------->
— (16 headers 0 lines) —
Creating new subscription
Sending to 172.28.3.149 : 5060 (NAT)
Found peer ‘pg5’ for ‘pg5’ from 172.28.3.149:5060
Looking for 4412490018 in device-hints (domain 172.28.3.211)
<— Transmitting (NAT) to 172.28.3.149:5060 —>
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 172.28.3.149:5060;branch=z9hG4bKPj88a12c9217484021866f300df85d6d77;received=172.28.3.149;rport=5060
From: “Femto” sip:pg5@172.28.3.211;tag=28aa7a96d406496fbc26c848e2627d05
To: sip:4412490018@172.28.3.211;tag=as3fe876e3
Call-ID: 0335c078e21a4fd89e9d3ac053690900
CSeq: 3626 SUBSCRIBE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
<------------>
Really destroying SIP dialog ‘0335c078e21a4fd89e9d3ac053690900’ Method: SUBSCRIBE
localhost*CLI>
<— SIP read from UDP:172.28.3.149:5060 —>
PUBLISH sip:pg5@172.28.3.211 SIP/2.0
Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPj67098175c1b5422781a697a74a9649c7
Max-Forwards: 70
From: “Femto” sip:pg5@172.28.3.211;tag=d6633b6b426a4663842c9681538c1b7a
To: “Femto” sip:pg5@172.28.3.211
Call-ID: 04326f0385c64517b8c9c3796f2a7b52
CSeq: 35139 PUBLISH
Event: presence
User-Agent: MicroSIP/3.1.7
Content-Type: application/pidf+xml
Content-Length: 283
-- Called 4412490018@ADC
localhostCLI>
– SIP/ADC-0000004c is circuit-busy
localhostCLI>
== Everyone is busy/congested at this time (1:0/1/0)
localhostCLI>
– Auto fallthrough, channel ‘SIP/pg5-0000004b’ status is 'CONGESTION’
localhostCLI>
<— Reliably Transmitting (NAT) to 172.28.3.149:5060 —>
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/UDP 172.28.3.149:5060;branch=z9hG4bKPj0805e5280288478a91051586f86a1aa5;received=172.28.3.149;rport=5060
From: “Femto” sip:pg5@172.28.3.211;tag=b0061bb240b843218a995512d0d18948
To: sip:4412490018@172.28.3.211;tag=as0edc7e8b
Call-ID: 1319651346d74c5e865572a27677cc6a
CSeq: 21958 INVITE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Require: timer
Session-Expires: 1800;refresher=uas
X-Asterisk-HangupCause: Unallocated (unassigned) number
X-Asterisk-HangupCauseCode: 1
Content-Length: 0
<------------>
localhostCLI>
<— SIP read from UDP:172.28.3.149:5060 —>
ACK sip:4412490018@172.28.3.211 SIP/2.0
Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPj0805e5280288478a91051586f86a1aa5
Max-Forwards: 70
From: “Femto” sip:pg5@172.28.3.211;tag=b0061bb240b843218a995512d0d18948
To: sip:4412490018@172.28.3.211;tag=as0edc7e8b
Call-ID: 1319651346d74c5e865572a27677cc6a
CSeq: 21958 ACK
Content-Length: 0
<------------->
— (8 headers 0 lines) —
Really destroying SIP dialog ‘3b6e9a501be0a08a1a8cf2587fbe6f8b@172.28.3.211’ Method: INVITE
localhostCLI>
<— SIP read from UDP:172.29.1.189:5060 —>
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 172.28.3.211:5060;branch=z9hG4bK16259a4e;rport
To: sip:4412490018@172.29.1.189
From: “Femto” sip:6018@172.28.3.211;tag=as4d875199
Call-ID: 3b6e9a501be0a08a1a8cf2587fbe6f8b@172.28.3.211
CSeq: 102 ACK
Content-Length: 0
<------------->
— (7 headers 0 lines) —
localhostCLI> e
<— SIP read from UDP:172.28.3.149:5060 —>
<------------->
localhostCLI> exit
[root@localhost ~]# [/code]
-- Called 4412490018@ADC
localhost*CLI>
<— SIP read from UDP:172.29.1.189:5060 —>
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 172.28.3.211:5060;branch=z9hG4bK16259a4e;rport
To: sip:4412490018@172.29.1.189
From: “Femto” sip:6018@172.28.3.211;tag=as4d875199
Call-ID: 3b6e9a501be0a08a1a8cf2587fbe6f8b@172.28.3.211
CSeq: 102 INVITE
Content-Length: 0
The MSC and the mobile phone are largely irrelevant. Also, MSCs predate SIP by one or two decades, so, if the MSC were relevant, it would be the particular model.
It looks like this is actually a SIP phone to cell phone call, not a cell to SIP one.
There is nothing that obviously distinguishes the SIP user agent in the MSC from any other SIP user agent.
The number you are sending is simply not a valid phone number, as far as the destination is concerned. It is too short for a UK number, in national format, so I doubt that it is looking for a +. It might be looking for + and a country code, maybe +1?
I doubt there is an international standard for combined MSC and SIP user agent devices, so you will have to experiment, or read the documentation.
Hi,
In this case, all the equipment is internal but unfortunately for me no one quite knows how to set it up 
It’s true that in this case, it was SIP to cell but (I take these things for granted) I would like to call in both directions to test the link.
The phone number in this case I think is irrelevant as all the equipment is internal (unless international dialling conventions are mandated in the equipment). I need to understand the generic rules on how to set-up the connections. SIP phones appear to identify themselves as @, mobiles as . So, a SIP user can just tap the in and the mobile rings. Similarly, the mobile needs to identify the SIP via a number rather than @. I’m expecting some translation, presumably in Asterisk, which converts to @.
Unfortunately for me if I find the documentation, I’ll read it 
The previous user of this system has set up the ADC MSC in sip.conf. The IP address is that of the BSC
[ADC]
type=peer
host=172.29.1.189
dtmfmode=rfc2833
qualify=yes
context=test
allow=g722
allow=gsm
allow=ilbc
I must be missing the connection on how Asterisk talks to the MSC and visa-versa.
Cheers
Femto.
The phone number is very relevant, because the call failed 404 Not Found, which normally means that the phone number was not in a recognizable format, or is unassigned.
(It is just possible that the destination is fussy about the exact form of the IP address, or domain name. Asterisk wouldn’t normally check that but your remote device might be different.)
Hi,
I meant that the format of the number was (probably) irrelevant but clearly the mapping/routing of numbers is not. If I could set up the system as ‘1’ for the mobile and ‘2’ for the SIP then that would be fine. I don’t even need a generic solution as only one mobile will talk to the SIP. I’m simply trying to get the two to communicate with each other.
Thank you [color=#0000FF]david55 [/color] for your help.
Cheers
Femto.
Hi,
Getting agonisingly close! Firstly the Asterisk IP address had changed not once but twice and the MSC was pointing to the incorrect place 
Now, on dialling 123453000 from a cell phone (4412490018) the SIP phone now rings. However, there is no audio from cell to SIP.
sip.conf
[123453000]
type=friend
host=dynamic
canreinvite=no
username=123453000
secret=MySecretCode
nat=yes
qualify=yes
mailbox=1000
context=test
allow=all
extensions.conf
[test]
exten=123453000,1,Log(NOTICE, Incoming call from ${CALLERID(all)})
exten=123453000,n,Dial(SIP/123453000)
exten=123453000,n,Answer
Any ideas gratefully received!
Cheers
Femto.
NAT and frewalls are the most common causes. It might also happen if one side negotiated G.729 but there were no licences.
For any more detailed debugging, you need to run at least debug level 5 on chan_sip and also have “sip set debug on” set. You need a log enabled for DEBUG class output.
Hi,
I’ve been assured by our IT that in this case, the firewall is allowing communications.
How do I set a debug level of 5 on chan_sip?
How do I get log enabled for DEBUG class output?
It seems that the only codec which will at least allow signalling to go through and keep the call up despite no audio is the iLBC one.
Cheers
Femto
wiki.asterisk.org/wiki/display/ … nformation
(This sets debugging for all modules. Use the built-in help if you want to limit it to just one.)
Hi,
I managed to get a log and it appears to go wrong from line 1412 (where the data starts below as the log is too long) onwards. Unfortunately I cannot translate it
Cheers
Femto
p.s. Thank you for your help [color=#0000FF]david55[/color]
<------------->
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 0 [ 33]: REGISTER sip:172.29.7.100 SIP/2.0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 1 [ 89]: Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPjf7025e01c54d4cb3808c67a75945c724
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 3 [ 87]: From: "" <sip:123453000@172.29.7.100>;tag=1851b2b901bd4ae297bf356fde62bcdb
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 4 [ 48]: To: "" <sip:123453000@172.29.7.100>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 5 [ 41]: Call-ID: 381a170e36f846d4b1fdfd8d6eba6dfa
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 6 [ 20]: CSeq: 40869 REGISTER
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 7 [ 26]: User-Agent: MicroSIP/3.1.7
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 8 [ 61]: Contact: "" <sip:123453000@172.28.3.149:5060;ob>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 9 [ 12]: Expires: 300
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 10 [ 90]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 11 [ 18]: Content-Length: 0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 12 [ 0]:
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: --- (12 headers 0 lines) ---
[Jul 24 10:44:14] DEBUG[3555] acl.c: Found IP address for this socket
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.29.7.100:5060
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Allocating new SIP dialog for 381a170e36f846d4b1fdfd8d6eba6dfa - REGISTER (No RTP)
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Initializing initreq for method REGISTER - callid 381a170e36f846d4b1fdfd8d6eba6dfa
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: Sending to 172.28.3.149 : 5060 (no NAT)
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c:
<--- Transmitting (NAT) to 172.28.3.149:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.28.3.149:5060;branch=z9hG4bKPjf7025e01c54d4cb3808c67a75945c724;received=172.28.3.149;rport=5060
From: "" <sip:123453000@172.29.7.100>;tag=1851b2b901bd4ae297bf356fde62bcdb
To: "" <sip:123453000@172.29.7.100>;tag=as3a079e7a
Call-ID: 381a170e36f846d4b1fdfd8d6eba6dfa
CSeq: 40869 REGISTER
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="450d64a5"
Content-Length: 0
<------------>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.3.149:5060
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: Scheduling destruction of SIP dialog '381a170e36f846d4b1fdfd8d6eba6dfa' in 32000 ms (Method: REGISTER)
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
REGISTER sip:172.29.7.100 SIP/2.0
Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPjfd70c6ea232d48858ecafbc0a5737716
Max-Forwards: 70
From: "" <sip:123453000@172.29.7.100>;tag=1851b2b901bd4ae297bf356fde62bcdb
To: "" <sip:123453000@172.29.7.100>
Call-ID: 381a170e36f846d4b1fdfd8d6eba6dfa
CSeq: 40870 REGISTER
User-Agent: MicroSIP/3.1.7
Contact: "" <sip:123453000@172.28.3.149:5060;ob>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Authorization: Digest username="123453000", realm="asterisk", nonce="450d64a5", uri="sip:172.29.7.100", response="478fee0c6077d14db2f0c9d6dcaa066d", algorithm=MD5
Content-Length: 0
<------------->
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 0 [ 33]: REGISTER sip:172.29.7.100 SIP/2.0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 1 [ 89]: Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPjfd70c6ea232d48858ecafbc0a5737716
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 3 [ 87]: From: "" <sip:123453000@172.29.7.100>;tag=1851b2b901bd4ae297bf356fde62bcdb
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 4 [ 48]: To: "" <sip:123453000@172.29.7.100>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 5 [ 41]: Call-ID: 381a170e36f846d4b1fdfd8d6eba6dfa
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 6 [ 20]: CSeq: 40870 REGISTER
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 7 [ 26]: User-Agent: MicroSIP/3.1.7
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 8 [ 61]: Contact: "" <sip:123453000@172.28.3.149:5060;ob>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 9 [ 12]: Expires: 300
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 10 [ 90]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 11 [162]: Authorization: Digest username="123453000", realm="asterisk", nonce="450d64a5", uri="sip:172.29.7.100", response="478fee0c6077d14db2f0c9d6dcaa066d", algorithm=MD5
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 12 [ 18]: Content-Length: 0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 13 [ 0]:
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: --- (13 headers 0 lines) ---
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Initializing initreq for method REGISTER - callid 381a170e36f846d4b1fdfd8d6eba6dfa
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: Sending to 172.28.3.149 : 5060 (NAT)
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Store REGISTER's src-IP:port for call routing.
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Allocating new SIP dialog for 51d330957e7a915950f7ae96359d4a37@127.0.0.1 - OPTIONS (No RTP)
[Jul 24 10:44:14] DEBUG[3555] acl.c: Found IP address for this socket
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.29.7.100:5060
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Initializing initreq for method OPTIONS - callid 23771251109c204c1b66f526137965e1@172.29.7.100
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 0 [ 50]: OPTIONS sip:123453000@172.28.3.149:5060;ob SIP/2.0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK56677287;rport
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 3 [ 59]: From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as1dcd69e7
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 4 [ 40]: To: <sip:123453000@172.28.3.149:5060;ob>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 5 [ 36]: Contact: <sip:asterisk@172.29.7.100>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 6 [ 54]: Call-ID: 23771251109c204c1b66f526137965e1@172.29.7.100
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 9 [ 35]: Date: Tue, 24 Jul 2012 09:44:14 GMT
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: Reliably Transmitting (NAT) to 172.28.3.149:5060:
OPTIONS sip:123453000@172.28.3.149:5060;ob SIP/2.0
Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK56677287;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as1dcd69e7
To: <sip:123453000@172.28.3.149:5060;ob>
Contact: <sip:asterisk@172.29.7.100>
Call-ID: 23771251109c204c1b66f526137965e1@172.29.7.100
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.2.11
Date: Tue, 24 Jul 2012 09:44:14 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
---
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #5637
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.28.3.149:5060
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c:
<--- Transmitting (NAT) to 172.28.3.149:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.28.3.149:5060;branch=z9hG4bKPjfd70c6ea232d48858ecafbc0a5737716;received=172.28.3.149;rport=5060
From: "" <sip:123453000@172.29.7.100>;tag=1851b2b901bd4ae297bf356fde62bcdb
To: "" <sip:123453000@172.29.7.100>;tag=as3a079e7a
Call-ID: 381a170e36f846d4b1fdfd8d6eba6dfa
CSeq: 40870 REGISTER
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Expires: 300
Contact: <sip:123453000@172.28.3.149:5060;ob>;expires=300
Date: Tue, 24 Jul 2012 09:44:14 GMT
Content-Length: 0
<------------>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.28.3.149:5060
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: Scheduling destruction of SIP dialog '381a170e36f846d4b1fdfd8d6eba6dfa' in 32000 ms (Method: REGISTER)
[Jul 24 10:44:14] DEBUG[3382] devicestate.c: No provider found, checking channel drivers for SIP - 123453000
[Jul 24 10:44:14] DEBUG[3382] chan_sip.c: Checking device state for peer 123453000
[Jul 24 10:44:14] DEBUG[3382] devicestate.c: Changing state for SIP/123453000 - state 1 (Not in use)
[Jul 24 10:44:14] DEBUG[3382] devicestate.c: device 'SIP/123453000' state '1'
[Jul 24 10:44:14] DEBUG[3542] app_queue.c: Device 'SIP/123453000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.29.7.100:5060;rport=5060;received=172.29.7.100;branch=z9hG4bK56677287
Call-ID: 23771251109c204c1b66f526137965e1@172.29.7.100
From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as1dcd69e7
To: <sip:123453000@172.28.3.149;ob>;tag=z9hG4bK56677287
CSeq: 102 OPTIONS
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
Supported: replaces, 100rel, timer, norefersub
Allow-Events: presence, message-summary, refer
User-Agent: MicroSIP/3.1.7
Content-Length: 0
<------------->
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 172.29.7.100:5060;rport=5060;received=172.29.7.100;branch=z9hG4bK56677287
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 2 [ 54]: Call-ID: 23771251109c204c1b66f526137965e1@172.29.7.100
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 3 [ 59]: From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as1dcd69e7
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 4 [ 55]: To: <sip:123453000@172.28.3.149;ob>;tag=z9hG4bK56677287
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 6 [ 90]: Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 7 [177]: Accept: application/sdp, application/pidf+xml, application/xpidf+xml, application/simple-message-summary, message/sipfrag;version=2.0, application/im-iscomposing+xml, text/plain
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 8 [ 46]: Supported: replaces, 100rel, timer, norefersub
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 9 [ 46]: Allow-Events: presence, message-summary, refer
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 10 [ 26]: User-Agent: MicroSIP/3.1.7
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 11 [ 18]: Content-Length: 0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 12 [ 0]:
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: --- (12 headers 0 lines) ---
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5637
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Stopping retransmission on '23771251109c204c1b66f526137965e1@172.29.7.100' of Request 102: Match Found
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Destroying SIP dialog 23771251109c204c1b66f526137965e1@172.29.7.100
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: Really destroying SIP dialog '23771251109c204c1b66f526137965e1@172.29.7.100' Method: OPTIONS
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
PUBLISH sip:123453000@172.29.7.100 SIP/2.0
Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPj4bbc74e4e30b47559eeef9f2dc9b91a2
Max-Forwards: 70
From: "" <sip:123453000@172.29.7.100>;tag=372469981df14d3fbe1542ad9e8d382a
To: "" <sip:123453000@172.29.7.100>
Call-ID: 85c9ce12ae474f04ba04893d59d31b9b
CSeq: 8070 PUBLISH
Event: presence
User-Agent: MicroSIP/3.1.7
Content-Type: application/pidf+xml
Content-Length: 289
<?xml version="1.0" encoding="UTF-8"?>
<presence entity="sip:123453000@172.29.7.100" xmlns="urn:ietf:params:xml:ns:pidf">
<tuple id="pj191e14ec466c4dc3b2da7b26d3e45b44">
<status>
<basic>open</basic>
</status>
<timestamp>2012-07-24T11:51:23.828Z</timestamp>
</tuple>
</presence>
<------------->
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 0 [ 42]: PUBLISH sip:123453000@172.29.7.100 SIP/2.0
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 1 [ 89]: Via: SIP/2.0/UDP 172.28.3.149:5060;rport;branch=z9hG4bKPj4bbc74e4e30b47559eeef9f2dc9b91a2
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 3 [ 87]: From: "" <sip:123453000@172.29.7.100>;tag=372469981df14d3fbe1542ad9e8d382a
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 4 [ 48]: To: "" <sip:123453000@172.29.7.100>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 5 [ 41]: Call-ID: 85c9ce12ae474f04ba04893d59d31b9b
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 6 [ 18]: CSeq: 8070 PUBLISH
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 7 [ 15]: Event: presence
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 8 [ 26]: User-Agent: MicroSIP/3.1.7
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 9 [ 34]: Content-Type: application/pidf+xml
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 10 [ 21]: Content-Length: 289
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Header 11 [ 0]:
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 0 [ 38]: <?xml version="1.0" encoding="UTF-8"?>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 1 [ 82]: <presence entity="sip:123453000@172.29.7.100" xmlns="urn:ietf:params:xml:ns:pidf">
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 2 [ 48]: <tuple id="pj191e14ec466c4dc3b2da7b26d3e45b44">
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 3 [ 10]: <status>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 4 [ 22]: <basic>open</basic>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 5 [ 11]: </status>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 6 [ 49]: <timestamp>2012-07-24T11:51:23.828Z</timestamp>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 7 [ 9]: </tuple>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Body 8 [ 11]: </presence>
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c: --- (11 headers 9 lines) ---
[Jul 24 10:44:14] DEBUG[3555] acl.c: Found IP address for this socket
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.29.7.100:5060
[Jul 24 10:44:14] VERBOSE[3555] chan_sip.c:
<--- Transmitting (no NAT) to 172.28.3.149:5060 --->
SIP/2.0 501 Method Not Implemented
Via: SIP/2.0/UDP 172.28.3.149:5060;branch=z9hG4bKPj4bbc74e4e30b47559eeef9f2dc9b91a2;received=172.28.3.149;rport=5060
From: "" <sip:123453000@172.29.7.100>;tag=372469981df14d3fbe1542ad9e8d382a
To: "" <sip:123453000@172.29.7.100>;tag=as5c25c81c
Call-ID: 85c9ce12ae474f04ba04893d59d31b9b
CSeq: 8070 PUBLISH
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
<------------>
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Trying to put 'SIP/2.0 501' onto UDP socket destined for 172.28.3.149:5060
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Got a request with unsupported SIP method.
[Jul 24 10:44:14] DEBUG[3555] chan_sip.c: Invalid SIP message - rejected , no callid, len 750
[Jul 24 10:44:14] DEBUG[11411] rtp.c: Got RTCP report of 52 bytes
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.29.1.189:5060 --->
BYE sip:123453000@172.29.7.100 SIP/2.0
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10322-1343133824
To: <sip:123453000@172.29.7.100;user=phone>;tag=as5b51fce7
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=90500E9872133D2
Call-ID: 169133D4500E9872@172.29.1.189
CSeq: 2 BYE
Allow: INVITE,ACK,BYE,CANCEL,UPDATE,REFER,NOTIFY,OPTIONS
Reason: Q.850;cause=16
Max-Forwards: 70
Content-Length: 0
<------------->
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 0 [ 38]: BYE sip:123453000@172.29.7.100 SIP/2.0
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 1 [ 66]: Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10322-1343133824
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 2 [ 58]: To: <sip:123453000@172.29.7.100;user=phone>;tag=as5b51fce7
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 3 [ 67]: From: <sip:+4412490018@172.29.1.189;user=phone>;tag=90500E9872133D2
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 4 [ 38]: Call-ID: 169133D4500E9872@172.29.1.189
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 5 [ 11]: CSeq: 2 BYE
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 6 [ 56]: Allow: INVITE,ACK,BYE,CANCEL,UPDATE,REFER,NOTIFY,OPTIONS
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 7 [ 22]: Reason: Q.850;cause=16
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 9 [ 17]: Content-Length: 0
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 10 [ 0]:
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c: --- (10 headers 0 lines) ---
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: **** Received BYE (8) - Command in SIP BYE
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Initializing initreq for method BYE - callid 169133D4500E9872@172.29.1.189
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c: Sending to 172.29.1.189 : 5060 (no NAT)
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Setting SIP_ALREADYGONE on dialog 169133D4500E9872@172.29.1.189
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Received bye, issuing owner hangup
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c:
<--- Transmitting (no NAT) to 172.29.1.189:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10322-1343133824;received=172.29.1.189
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=90500E9872133D2
To: <sip:123453000@172.29.7.100;user=phone>;tag=as5b51fce7
Call-ID: 169133D4500E9872@172.29.1.189
CSeq: 2 BYE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
<------------>
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.29.1.189:5060
[Jul 24 10:44:16] DEBUG[11411] rtp.c: p2p-rtp-bridge: Ooh, got a hangup
[Jul 24 10:44:16] DEBUG[11411] channel.c: Returning from native bridge, channels: SIP/ADC-0000006e, SIP/123453000-0000006f
[Jul 24 10:44:16] DEBUG[11411] channel.c: Hanging up channel 'SIP/123453000-0000006f'
[Jul 24 10:44:16] DEBUG[11411] chan_sip.c: Hangup call SIP/123453000-0000006f, SIP callid 1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100
[Jul 24 10:44:16] VERBOSE[11411] chan_sip.c: Scheduling destruction of SIP dialog '1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100' in 6400 ms (Method: INVITE)
[Jul 24 10:44:16] DEBUG[11411] chan_sip.c: Strict routing enforced for session 1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100
[Jul 24 10:44:16] VERBOSE[11411] chan_sip.c: set_destination: Parsing <sip:172.28.3.149:5060> for address/port to send to
[Jul 24 10:44:16] VERBOSE[11411] chan_sip.c: set_destination: set destination to 172.28.3.149, port 5060
[Jul 24 10:44:16] VERBOSE[11411] chan_sip.c: Reliably Transmitting (NAT) to 172.28.3.149:5060:
BYE sip:172.28.3.149:5060 SIP/2.0
Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK03c96c6e;rport
Max-Forwards: 70
From: "" <sip:+4412490018@172.29.7.100>;tag=as75b7e129
To: <sip:123453000@172.28.3.149:5060;ob>;tag=f373f181419e4687bf11a1f2a9dfafe0
Call-ID: 1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100
CSeq: 103 BYE
User-Agent: Asterisk PBX 1.6.2.11
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0
---
[Jul 24 10:44:16] DEBUG[11411] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #5642
[Jul 24 10:44:16] DEBUG[11411] chan_sip.c: Trying to put 'BYE sip:172' onto UDP socket destined for 172.28.3.149:5060
[Jul 24 10:44:16] DEBUG[11411] rtp.c: Channel '<unspecified>' has no RTP, not doing anything
[Jul 24 10:44:16] DEBUG[3382] devicestate.c: No provider found, checking channel drivers for SIP - 123453000
[Jul 24 10:44:16] DEBUG[11411] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Jul 24 10:44:16] DEBUG[3382] chan_sip.c: Checking device state for peer 123453000
[Jul 24 10:44:16] DEBUG[11411] pbx.c: Spawn extension (test,123453000,3) exited non-zero on 'SIP/ADC-0000006e'
[Jul 24 10:44:16] DEBUG[3382] devicestate.c: Changing state for SIP/123453000 - state 1 (Not in use)
[Jul 24 10:44:16] DEBUG[3382] devicestate.c: device 'SIP/123453000' state '1'
[Jul 24 10:44:16] DEBUG[3542] app_queue.c: Device 'SIP/123453000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jul 24 10:44:16] VERBOSE[11411] pbx.c: == Spawn extension (test, 123453000, 3) exited non-zero on 'SIP/ADC-0000006e'
[Jul 24 10:44:16] DEBUG[11411] channel.c: Soft-Hanging up channel 'SIP/ADC-0000006e'
[Jul 24 10:44:16] DEBUG[11411] channel.c: Hanging up channel 'SIP/ADC-0000006e'
[Jul 24 10:44:16] DEBUG[11411] chan_sip.c: Hangup call SIP/ADC-0000006e, SIP callid 169133D4500E9872@172.29.1.189
[Jul 24 10:44:16] DEBUG[3382] devicestate.c: No provider found, checking channel drivers for SIP - ADC
[Jul 24 10:44:16] DEBUG[3382] chan_sip.c: Checking device state for peer ADC
[Jul 24 10:44:16] DEBUG[3382] devicestate.c: Changing state for SIP/ADC - state 1 (Not in use)
[Jul 24 10:44:16] DEBUG[3382] devicestate.c: device 'SIP/ADC' state '1'
[Jul 24 10:44:16] DEBUG[3542] app_queue.c: Device 'SIP/ADC' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.29.7.100:5060;rport=5060;received=172.29.7.100;branch=z9hG4bK03c96c6e
Call-ID: 1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100
From: "" <sip:+4412490018@172.29.7.100>;tag=as75b7e129
To: <sip:123453000@172.28.3.149;ob>;tag=f373f181419e4687bf11a1f2a9dfafe0
CSeq: 103 BYE
Content-Length: 0
<------------->
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 172.29.7.100:5060;rport=5060;received=172.29.7.100;branch=z9hG4bK03c96c6e
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 2 [ 54]: Call-ID: 1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 3 [ 67]: From: "" <sip:+4412490018@172.29.7.100>;tag=as75b7e129
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 4 [ 72]: To: <sip:123453000@172.28.3.149;ob>;tag=f373f181419e4687bf11a1f2a9dfafe0
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 5 [ 13]: CSeq: 103 BYE
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 6 [ 18]: Content-Length: 0
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Header 7 [ 0]:
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c: --- (7 headers 0 lines) ---
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5642
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Stopping retransmission on '1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100' of Request 103: Match Found
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Destroying SIP dialog 1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c: Really destroying SIP dialog '1ad0747a1f712ce17d90b9f548f3bfab@172.29.7.100' Method: INVITE
[Jul 24 10:44:16] DEBUG[3555] chan_sip.c: Destroying SIP dialog 169133D4500E9872@172.29.1.189
[Jul 24 10:44:16] VERBOSE[3555] chan_sip.c: Really destroying SIP dialog '169133D4500E9872@172.29.1.189' Method: BYE
[Jul 24 10:44:17] DEBUG[11414] http.c: mmm ... cookie! Name: 'mansession_id' Value: '25e1786b'
[Jul 24 10:44:17] DEBUG[11414] http.c: mmm ... cookie! Name: 'username' Value: 'admin'
[Jul 24 10:44:17] DEBUG[11414] http.c: mmm ... cookie! Name: 'rwaccess' Value: 'yes'
[Jul 24 10:44:17] DEBUG[11414] http.c: mmm ... cookie! Name: 'advancedmode' Value: 'yes'
[Jul 24 10:44:17] DEBUG[11414] http.c: match request [rawman] with handler [httpstatus] len 0
[Jul 24 10:44:17] DEBUG[11414] http.c: match request [rawman] with handler [phoneprov] len 10
[Jul 24 10:44:17] DEBUG[11414] http.c: match request [rawman] with handler [manager] len 9
[Jul 24 10:44:17] DEBUG[11414] http.c: match request [rawman] with handler [rawman] len 7
[Jul 24 10:44:17] VERBOSE[11414] manager.c: > HTTP Manager add header action: ping
[Jul 24 10:44:17] VERBOSE[11414] manager.c: > HTTP Manager add header advancedmode: yes
[Jul 24 10:44:17] VERBOSE[11414] manager.c: > HTTP Manager add header rwaccess: yes
[Jul 24 10:44:17] VERBOSE[11414] manager.c: > HTTP Manager add header username: admin
[Jul 24 10:44:17] VERBOSE[11414] manager.c: > HTTP Manager add header mansession_id: 25e1786b
[Jul 24 10:44:17] DEBUG[11414] manager.c: Manager received command 'ping'
[Jul 24 10:44:22] DEBUG[11415] http.c: mmm ... cookie! Name: 'mansession_id' Value: '25e1786b'
[Jul 24 10:44:22] DEBUG[11415] http.c: mmm ... cookie! Name: 'username' Value: 'admin'
[Jul 24 10:44:22] DEBUG[11415] http.c: mmm ... cookie! Name: 'rwaccess' Value: 'yes'
[Jul 24 10:44:22] DEBUG[11415] http.c: mmm ... cookie! Name: 'advancedmode' Value: 'yes'
[Jul 24 10:44:22] DEBUG[11415] http.c: match request [rawman] with handler [httpstatus] len 0
[Jul 24 10:44:22] DEBUG[11415] http.c: match request [rawman] with handler [phoneprov] len 10
[Jul 24 10:44:22] DEBUG[11415] http.c: match request [rawman] with handler [manager] len 9
[Jul 24 10:44:22] DEBUG[11415] http.c: match request [rawman] with handler [rawman] len 7
[Jul 24 10:44:22] VERBOSE[11415] manager.c: > HTTP Manager add header action: ping
[Jul 24 10:44:22] VERBOSE[11415] manager.c: > HTTP Manager add header advancedmode: yes
[Jul 24 10:44:22] VERBOSE[11415] manager.c: > HTTP Manager add header rwaccess: yes
[Jul 24 10:44:22] VERBOSE[11415] manager.c: > HTTP Manager add header username: admin
[Jul 24 10:44:22] VERBOSE[11415] manager.c: > HTTP Manager add header mansession_id: 25e1786b
[Jul 24 10:44:22] DEBUG[11415] manager.c: Manager received command 'ping'
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Allocating new SIP dialog for 3ce4d1297e72e5e257e1407b55184e8f@127.0.0.1 - OPTIONS (No RTP)
[Jul 24 10:44:25] DEBUG[3555] acl.c: Found IP address for this socket
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 172.29.7.100:5060
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Initializing initreq for method OPTIONS - callid 70b207e7237702c56865ba8a302ffad6@172.29.7.100
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 0 [ 32]: OPTIONS sip:172.29.1.189 SIP/2.0
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK43e69085;rport
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 3 [ 59]: From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as5dc7b460
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 4 [ 22]: To: <sip:172.29.1.189>
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 5 [ 36]: Contact: <sip:asterisk@172.29.7.100>
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 6 [ 54]: Call-ID: 70b207e7237702c56865ba8a302ffad6@172.29.7.100
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.2.11
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 9 [ 35]: Date: Tue, 24 Jul 2012 09:44:25 GMT
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer
[Jul 24 10:44:25] VERBOSE[3555] chan_sip.c: Reliably Transmitting (no NAT) to 172.29.1.189:5060:
OPTIONS sip:172.29.1.189 SIP/2.0
Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK43e69085;rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as5dc7b460
To: <sip:172.29.1.189>
Contact: <sip:asterisk@172.29.7.100>
Call-ID: 70b207e7237702c56865ba8a302ffad6@172.29.7.100
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.6.2.11
Date: Tue, 24 Jul 2012 09:44:25 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
---
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #5643
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.29.1.189:5060
[Jul 24 10:44:25] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.29.1.189:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK43e69085;rport
To: <sip:172.29.1.189>
From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as5dc7b460
Call-ID: 70b207e7237702c56865ba8a302ffad6@172.29.7.100
CSeq: 102 OPTIONS
Allow: INVITE,ACK,BYE,CANCEL,UPDATE,OPTIONS
Content-Length: 0
<------------->
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK43e69085;rport
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 2 [ 22]: To: <sip:172.29.1.189>
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 3 [ 59]: From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as5dc7b460
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 4 [ 54]: Call-ID: 70b207e7237702c56865ba8a302ffad6@172.29.7.100
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 6 [ 43]: Allow: INVITE,ACK,BYE,CANCEL,UPDATE,OPTIONS
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 7 [ 17]: Content-Length: 0
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Header 8 [ 0]:
[Jul 24 10:44:25] VERBOSE[3555] chan_sip.c: --- (8 headers 0 lines) ---
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5643
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Stopping retransmission on '70b207e7237702c56865ba8a302ffad6@172.29.7.100' of Request 102: Match Found
[Jul 24 10:44:25] DEBUG[3555] chan_sip.c: Destroying SIP dialog 70b207e7237702c56865ba8a302ffad6@172.29.7.100
[Jul 24 10:44:25] VERBOSE[3555] chan_sip.c: Really destroying SIP dialog '70b207e7237702c56865ba8a302ffad6@172.29.7.100' Method: OPTIONS
[Jul 24 10:44:27] DEBUG[11416] http.c: mmm ... cookie! Name: 'mansession_id' Value: '25e1786b'
[Jul 24 10:44:27] DEBUG[11416] http.c: mmm ... cookie! Name: 'username' Value: 'admin'
[Jul 24 10:44:27] DEBUG[11416] http.c: mmm ... cookie! Name: 'rwaccess' Value: 'yes'
[Jul 24 10:44:27] DEBUG[11416] http.c: mmm ... cookie! Name: 'advancedmode' Value: 'yes'
[Jul 24 10:44:27] DEBUG[11416] http.c: match request [rawman] with handler [httpstatus] len 0
[Jul 24 10:44:27] DEBUG[11416] http.c: match request [rawman] with handler [phoneprov] len 10
[Jul 24 10:44:27] DEBUG[11416] http.c: match request [rawman] with handler [manager] len 9
[Jul 24 10:44:27] DEBUG[11416] http.c: match request [rawman] with handler [rawman] len 7
[Jul 24 10:44:27] VERBOSE[11416] manager.c: > HTTP Manager add header action: ping
[Jul 24 10:44:27] VERBOSE[11416] manager.c: > HTTP Manager add header advancedmode: yes
[Jul 24 10:44:27] VERBOSE[11416] manager.c: > HTTP Manager add header rwaccess: yes
[Jul 24 10:44:27] VERBOSE[11416] manager.c: > HTTP Manager add header username: admin
[Jul 24 10:44:27] VERBOSE[11416] manager.c: > HTTP Manager add header mansession_id: 25e1786b
[Jul 24 10:44:27] DEBUG[11416] manager.c: Manager received command 'ping'
[Jul 24 10:44:29] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
<------------->
[Jul 24 10:44:29] DEBUG[3555] chan_sip.c: Header 0 [ 0]:
[Jul 24 10:44:32] DEBUG[11417] http.c: mmm ... cookie! Name: 'mansession_id' Value: '25e1786b'
[Jul 24 10:44:32] DEBUG[11417] http.c: mmm ... cookie! Name: 'username' Value: 'admin'
[Jul 24 10:44:32] DEBUG[11417] http.c: mmm ... cookie! Name: 'rwaccess' Value: 'yes'
[Jul 24 10:44:32] DEBUG[11417] http.c: mmm ... cookie! Name: 'advancedmode' Value: 'yes'
[Jul 24 10:44:32] DEBUG[11417] http.c: match request [rawman] with handler [httpstatus] len 0
[Jul 24 10:44:32] DEBUG[11417] http.c: match request [rawman] with handler [phoneprov] len 10
[Jul 24 10:44:32] DEBUG[11417] http.c: match request [rawman] with handler [manager] len 9
[Jul 24 10:44:32] DEBUG[11417] http.c: match request [rawman] with handler [rawman] len 7
[Jul 24 10:44:32] VERBOSE[11417] manager.c: > HTTP Manager add header action: ping
[Jul 24 10:44:32] VERBOSE[11417] manager.c: > HTTP Manager add header advancedmode: yes
[Jul 24 10:44:32] VERBOSE[11417] manager.c: > HTTP Manager add header rwaccess: yes
[Jul 24 10:44:32] VERBOSE[11417] manager.c: > HTTP Manager add header username: admin
[Jul 24 10:44:32] VERBOSE[11417] manager.c: > HTTP Manager add header mansession_id: 25e1786b
[Jul 24 10:44:32] DEBUG[11417] manager.c: Manager received command 'ping'
[Jul 24 10:44:33] DEBUG[11418] http.c: mmm ... cookie! Name: 'mansession_id' Value: '25e1786b'
[Jul 24 10:44:33] DEBUG[11418] http.c: mmm ... cookie! Name: 'username' Value: 'admin'
[Jul 24 10:44:33] DEBUG[11418] http.c: mmm ... cookie! Name: 'rwaccess' Value: 'yes'
[Jul 24 10:44:33] DEBUG[11418] http.c: mmm ... cookie! Name: 'advancedmode' Value: 'yes'
[Jul 24 10:44:33] DEBUG[11418] http.c: match request [rawman] with handler [httpstatus] len 0
[Jul 24 10:44:33] DEBUG[11418] http.c: match request [rawman] with handler [phoneprov] len 10
[Jul 24 10:44:33] DEBUG[11418] http.c: match request [rawman] with handler [manager] len 9
[Jul 24 10:44:33] DEBUG[11418] http.c: match request [rawman] with handler [rawman] len 7
[Jul 24 10:44:33] VERBOSE[11418] manager.c: > HTTP Manager add header action: command
[Jul 24 10:44:33] VERBOSE[11418] manager.c: > HTTP Manager add header command: core set debug 0
[Jul 24 10:44:33] VERBOSE[11418] manager.c: > HTTP Manager add header advancedmode: yes
[Jul 24 10:44:33] VERBOSE[11418] manager.c: > HTTP Manager add header rwaccess: yes
[Jul 24 10:44:33] VERBOSE[11418] manager.c: > HTTP Manager add header username: admin
[Jul 24 10:44:33] VERBOSE[11418] manager.c: > HTTP Manager add header mansession_id: 25e1786b
[Jul 24 10:44:33] DEBUG[11418] manager.c: Manager received command 'command'
[Jul 24 10:44:37] VERBOSE[11419] manager.c: > HTTP Manager add header action: command
[Jul 24 10:44:37] VERBOSE[11419] manager.c: > HTTP Manager add header command: core set verbose 0
[Jul 24 10:44:37] VERBOSE[11419] manager.c: > HTTP Manager add header advancedmode: yes
[Jul 24 10:44:37] VERBOSE[11419] manager.c: > HTTP Manager add header rwaccess: yes
[Jul 24 10:44:37] VERBOSE[11419] manager.c: > HTTP Manager add header username: admin
[Jul 24 10:44:37] VERBOSE[11419] manager.c: > HTTP Manager add header mansession_id: 25e1786b
[Jul 24 10:44:44] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
<------------->
[Jul 24 10:44:46] VERBOSE[3555] chan_sip.c: Really destroying SIP dialog '381a170e36f846d4b1fdfd8d6eba6dfa' Method: REGISTER
[Jul 24 10:44:59] VERBOSE[3555] chan_sip.c:
<--- SIP read from UDP:172.28.3.149:5060 --->
<------------->Hi,
It seems odd that the only codec I can get to negotiate is ‘ILBC’. So as an aside, had took several logs at the various system elements to see the codec type translation. The cell phone originates GSM-EFR. I took a log at the MSC and there is a…
X-Asterisk-HangupCauseCode: 58
[Expert Info (Note/Undecoded): Unrecognised SIP header (X-Asterisk-HangupCauseCode)]
[Message: Unrecognised SIP header (X-Asterisk-HangupCauseCode)]
[Severity level: Note]
[Group: Undecoded]
Content-Length: 0
error.
No. Time Source Destination Protocol Length Info
812 10.546108 172.29.1.189 172.29.7.100 SIP/SDP 705 Request: INVITE sip:123453000@172.29.7.100;user=phone, with session description
Frame 812: 705 bytes on wire (5640 bits), 705 bytes captured (5640 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.1.189 (172.29.1.189), Dst: 172.29.7.100 (172.29.7.100)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Request-Line: INVITE sip:123453000@172.29.7.100;user=phone SIP/2.0
Method: INVITE
Request-URI: sip:123453000@172.29.7.100;user=phone
[Resent Packet: False]
Message Header
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10419-1343152253
Transport: UDP
Sent-by Address: 172.29.1.189
Sent-by port: 5060
Branch: z9hG4bK-10419-1343152253
To: <sip:123453000@172.29.7.100;user=phone>
SIP to address: sip:123453000@172.29.7.100;user=phone
SIP to address User Part: 123453000
SIP to address Host Part: 172.29.7.100
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=BA500EE07D97299
SIP from address: sip:+4412490018@172.29.1.189;user=phone
SIP tag: BA500EE07D97299
Call-ID: 1C39729B500EE07D@172.29.1.189
CSeq: 1 INVITE
Sequence Number: 1
Method: INVITE
Contact: <sip:+4412490018@172.29.1.189>
Contact-URI: sip:+4412490018@172.29.1.189
Contactt-URI User Part: +4412490018
Contact-URI Host Part: 172.29.1.189
Allow: INVITE,ACK,BYE,CANCEL,UPDATE,REFER,NOTIFY,OPTIONS
P-Asserted-Identity: sip:+4412490018@172.29.1.189
SIP PAI Address: sip:+4412490018@172.29.1.189
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 147
Message Body
Session Description Protocol
Session Description Protocol Version (v): 0
Owner/Creator, Session Id (o): - 1343145504184 1343145504184 IN IP4 172.29.7.13
Session Name (s): -
Connection Information (c): IN IP4 172.29.7.13
Media Description, name and address (m): audio 4184 RTP/AVP 97
Media Attribute (a): rtpmap:97 GSM-EFR/8000
Media Attribute Fieldname: rtpmap
Media Format: 97
MIME Type: GSM-EFR
Sample Rate: 8000
Media Attribute (a): sendrecv
No. Time Source Destination Protocol Length Info
813 10.546988 172.29.7.100 172.29.1.189 SIP 517 Status: 100 Trying
Frame 813: 517 bytes on wire (4136 bits), 517 bytes captured (4136 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.7.100 (172.29.7.100), Dst: 172.29.1.189 (172.29.1.189)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Status-Line: SIP/2.0 100 Trying
Status-Code: 100
[Resent Packet: False]
[Request Frame: 812]
[Response Time (ms): 0]
Message Header
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10419-1343152253;received=172.29.1.189
Transport: UDP
Sent-by Address: 172.29.1.189
Sent-by port: 5060
Branch: z9hG4bK-10419-1343152253
Received: 172.29.1.189
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=BA500EE07D97299
SIP from address: sip:+4412490018@172.29.1.189;user=phone
SIP tag: BA500EE07D97299
To: <sip:123453000@172.29.7.100;user=phone>
SIP to address: sip:123453000@172.29.7.100;user=phone
SIP to address User Part: 123453000
SIP to address Host Part: 172.29.7.100
Call-ID: 1C39729B500EE07D@172.29.1.189
CSeq: 1 INVITE
Sequence Number: 1
Method: INVITE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:123453000@172.29.7.100>
Contact-URI: sip:123453000@172.29.7.100
Contactt-URI User Part: 123453000
Contact-URI Host Part: 172.29.7.100
Content-Length: 0
No. Time Source Destination Protocol Length Info
817 10.563183 172.29.7.100 172.29.1.189 SIP 533 Status: 180 Ringing
Frame 817: 533 bytes on wire (4264 bits), 533 bytes captured (4264 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.7.100 (172.29.7.100), Dst: 172.29.1.189 (172.29.1.189)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Status-Line: SIP/2.0 180 Ringing
Status-Code: 180
[Resent Packet: False]
[Request Frame: 812]
[Response Time (ms): 17]
Message Header
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10419-1343152253;received=172.29.1.189
Transport: UDP
Sent-by Address: 172.29.1.189
Sent-by port: 5060
Branch: z9hG4bK-10419-1343152253
Received: 172.29.1.189
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=BA500EE07D97299
SIP from address: sip:+4412490018@172.29.1.189;user=phone
SIP tag: BA500EE07D97299
To: <sip:123453000@172.29.7.100;user=phone>;tag=as08e64d27
SIP to address: sip:123453000@172.29.7.100;user=phone
SIP to address User Part: 123453000
SIP to address Host Part: 172.29.7.100
SIP tag: as08e64d27
Call-ID: 1C39729B500EE07D@172.29.1.189
CSeq: 1 INVITE
Sequence Number: 1
Method: INVITE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: <sip:123453000@172.29.7.100>
Contact-URI: sip:123453000@172.29.7.100
Contactt-URI User Part: 123453000
Contact-URI Host Part: 172.29.7.100
Content-Length: 0
No. Time Source Destination Protocol Length Info
1042 13.407618 172.29.7.100 172.29.1.189 SIP 595 Status: 503 Service Unavailable
Frame 1042: 595 bytes on wire (4760 bits), 595 bytes captured (4760 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.7.100 (172.29.7.100), Dst: 172.29.1.189 (172.29.1.189)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Status-Line: SIP/2.0 503 Service Unavailable
Status-Code: 503
[Resent Packet: False]
[Request Frame: 812]
[Response Time (ms): 2862]
Message Header
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10419-1343152253;received=172.29.1.189
Transport: UDP
Sent-by Address: 172.29.1.189
Sent-by port: 5060
Branch: z9hG4bK-10419-1343152253
Received: 172.29.1.189
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=BA500EE07D97299
SIP from address: sip:+4412490018@172.29.1.189;user=phone
SIP tag: BA500EE07D97299
To: <sip:123453000@172.29.7.100;user=phone>;tag=as08e64d27
SIP to address: sip:123453000@172.29.7.100;user=phone
SIP to address User Part: 123453000
SIP to address Host Part: 172.29.7.100
SIP tag: as08e64d27
Call-ID: 1C39729B500EE07D@172.29.1.189
CSeq: 1 INVITE
Sequence Number: 1
Method: INVITE
Server: Asterisk PBX 1.6.2.11
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
X-Asterisk-HangupCause: Bearer capability not available
[Expert Info (Note/Undecoded): Unrecognised SIP header (X-Asterisk-HangupCause)]
[Message: Unrecognised SIP header (X-Asterisk-HangupCause)]
[Severity level: Note]
[Group: Undecoded]
X-Asterisk-HangupCauseCode: 58
[Expert Info (Note/Undecoded): Unrecognised SIP header (X-Asterisk-HangupCauseCode)]
[Message: Unrecognised SIP header (X-Asterisk-HangupCauseCode)]
[Severity level: Note]
[Group: Undecoded]
Content-Length: 0
No. Time Source Destination Protocol Length Info
1043 13.415258 172.29.1.189 172.29.7.100 SIP 384 Request: ACK sip:123453000@172.29.7.100;user=phone
Frame 1043: 384 bytes on wire (3072 bits), 384 bytes captured (3072 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.1.189 (172.29.1.189), Dst: 172.29.7.100 (172.29.7.100)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Request-Line: ACK sip:123453000@172.29.7.100;user=phone SIP/2.0
Method: ACK
Request-URI: sip:123453000@172.29.7.100;user=phone
[Resent Packet: False]
[Request Frame: 812]
[Response Time (ms): 2870]
Message Header
Via: SIP/2.0/UDP 172.29.1.189:5060;branch=z9hG4bK-10419-1343152253
Transport: UDP
Sent-by Address: 172.29.1.189
Sent-by port: 5060
Branch: z9hG4bK-10419-1343152253
To: <sip:123453000@172.29.7.100;user=phone>;tag=as08e64d27
SIP to address: sip:123453000@172.29.7.100;user=phone
SIP to address User Part: 123453000
SIP to address Host Part: 172.29.7.100
SIP tag: as08e64d27
From: <sip:+4412490018@172.29.1.189;user=phone>;tag=BA500EE07D97299
SIP from address: sip:+4412490018@172.29.1.189;user=phone
SIP tag: BA500EE07D97299
Call-ID: 1C39729B500EE07D@172.29.1.189
CSeq: 1 ACK
Sequence Number: 1
Method: ACK
Max-Forwards: 70
Content-Length: 0
No. Time Source Destination Protocol Length Info
1327 17.293223 172.29.7.100 172.29.1.189 SIP 554 Request: OPTIONS sip:172.29.1.189
Frame 1327: 554 bytes on wire (4432 bits), 554 bytes captured (4432 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.7.100 (172.29.7.100), Dst: 172.29.1.189 (172.29.1.189)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Request-Line: OPTIONS sip:172.29.1.189 SIP/2.0
Method: OPTIONS
Request-URI: sip:172.29.1.189
[Resent Packet: False]
Message Header
Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK4ba05ac9;rport
Transport: UDP
Sent-by Address: 172.29.7.100
Sent-by port: 5060
Branch: z9hG4bK4ba05ac9
RPort: rport
Max-Forwards: 70
From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as5d7ae94f
SIP Display info: "asterisk"
SIP from address: sip:asterisk@172.29.7.100
SIP tag: as5d7ae94f
To: <sip:172.29.1.189>
SIP to address: sip:172.29.1.189
SIP to address Host Part: 172.29.1.189
Contact: <sip:asterisk@172.29.7.100>
Contact-URI: sip:asterisk@172.29.7.100
Contactt-URI User Part: asterisk
Contact-URI Host Part: 172.29.7.100
Call-ID: 3c3480607af8b62374be1ce040d2185d@172.29.7.100
CSeq: 102 OPTIONS
Sequence Number: 102
Method: OPTIONS
User-Agent: Asterisk PBX 1.6.2.11
Date: Tue, 24 Jul 2012 14:51:33 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0
No. Time Source Destination Protocol Length Info
1328 17.295657 172.29.1.189 172.29.7.100 SIP 351 Status: 200 OK
Frame 1328: 351 bytes on wire (2808 bits), 351 bytes captured (2808 bits)
Linux cooked capture
Internet Protocol Version 4, Src: 172.29.1.189 (172.29.1.189), Dst: 172.29.7.100 (172.29.7.100)
User Datagram Protocol, Src Port: sip (5060), Dst Port: sip (5060)
Session Initiation Protocol
Status-Line: SIP/2.0 200 OK
Status-Code: 200
[Resent Packet: False]
[Request Frame: 1327]
[Response Time (ms): 2]
Message Header
Via: SIP/2.0/UDP 172.29.7.100:5060;branch=z9hG4bK4ba05ac9;rport
Transport: UDP
Sent-by Address: 172.29.7.100
Sent-by port: 5060
Branch: z9hG4bK4ba05ac9
RPort: rport
To: <sip:172.29.1.189>
SIP to address: sip:172.29.1.189
SIP to address Host Part: 172.29.1.189
From: "asterisk" <sip:asterisk@172.29.7.100>;tag=as5d7ae94f
SIP Display info: "asterisk"
SIP from address: sip:asterisk@172.29.7.100
SIP tag: as5d7ae94f
Call-ID: 3c3480607af8b62374be1ce040d2185d@172.29.7.100
CSeq: 102 OPTIONS
Sequence Number: 102
Method: OPTIONS
Allow: INVITE,ACK,BYE,CANCEL,UPDATE,OPTIONS
Content-Length: 0Cheers
Femto
Asterisk only supports standard, full rate, GSM coding, not enhanced full rate coding. The call is being rejected because there are no codecs in common. GSM-EFR was the only one offered.
I think you will find that restriction fairly common in the VoIP world.
OK. I’m speculating here but I suspect most 2G phones will originate the call with GSM-EFR (as seen in my example). Indeed if iLBC is enabled on the SIP phone, then at least signalling appears to work. There seems to be some translation going on.
sip.conf seems to ‘allow’ codecs and in that case it must act as a pipe to allow traffic through the gateway. Does the Asterisk codec restriction only apply when it is required to answer a call?
I have logged the ‘INVITE’ from X-Lite to see what codec types it offers in SDP.
X-Lite
SIP/SDP protocol
Media format…
GSM Codec 0x33 ‘3’ -> GSM 06.10 == FR/GSM-FR
G711 aLaw 0x38 ‘8’ -> ITU-T G.711 PCMA
G711 uLaw 0x30 ‘0’ -> ITU-T G.711 PCMU
iLBC Codec 0x39 0x38 ‘98’ -> iLBC/8000
Cheers
Femto