Hello,
I had posted this question earlier on asterisk-users, but didn't receive
any reply, so I'm posting on sr-users in the hope that someone can
provide guidance on how to debug this problem.
Our setup involves a Sip softphone registering with a fresh install of
Asterisk v1.6.0.5 through an outbound proxy (Kamailio v3.1.1).
We observe that about 80% of the time, immediately after startup of the
softphone, when the softphone sends a REGISTER message, Asterisk replies
with a "503 Server error". However, subsequent REGISTER messages are
replied to appropriately (with a 401 Unauthorized).
There are very few devices (under 5) registered with Asterisk, so this
is not an overload issue.
Please find attached a SIP trace for device registration.
- What might cause this behavior in Asterisk ?
- Are there any config file parameters that require to be changed ?
- Would it help to see any other specific logs, if so which ones ?
Thanks and Regards,
Vikram.
<--- SIP read from UDP://Proxy_IP:9090 --->
REGISTER sip:Asterisk_IP:5060 SIP/2.0
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK54ba.4a00e294.0
Via: SIP/2.0/UDP
192.168.3.6:7160;received=Nat_IP;rport=62842;branch=z9hG4bKPju8xsdcZ1vD7-ykHX33rq78nBeEJ3k-eP
Route: <sip:Proxy_IP:9090;lr>
Max-Forwards: 69
From: "12345" <sip:12...@asterisk_ip>;tag=fCMU.J88N4jATP5d3d6zjXPbFyWAbz6Q
To: "12345" <sip:12...@asterisk_ip>
Call-ID: 1o-UnqLhb-j4dSzDzHThXhF0uE-nQu4Z
CSeq: 34464 REGISTER
Contact: "12345" <sip:12...@192.168.3.6:7160>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Content-Length: 0
P-hint: outbound
<------------->
--- (14 headers 0 lines) ---
<--- Transmitting (NAT) to Proxy_IP:9090 --->
SIP/2.0 503 Server error
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK54ba.4a00e294.0;received=Proxy_IP
Via: SIP/2.0/UDP
192.168.3.6:7160;received=Nat_IP;rport=62842;branch=z9hG4bKPju8xsdcZ1vD7-ykHX33rq78nBeEJ3k-eP
From: "12345" <sip:12...@asterisk_ip>;tag=fCMU.J88N4jATP5d3d6zjXPbFyWAbz6Q
To: "12345" <sip:12...@asterisk_ip>;tag=as56bde503
Call-ID: 1o-UnqLhb-j4dSzDzHThXhF0uE-nQu4Z
CSeq: 34464 REGISTER
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Contact: <sip:12...@asterisk_ip>
Content-Length: 0
<------------>
ser15*CLI>
<--- SIP read from UDP://Proxy_IP:9090 --->
REGISTER sip:Asterisk_IP:5060 SIP/2.0
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK4d68.177229a5.0
Via: SIP/2.0/UDP
192.168.3.6:7160;received=Nat_IP;rport=62842;branch=z9hG4bKPjTxWqFoP7fl2s1ZB8O.4wLyLKmEnW.2uX
Route: <sip:Proxy_IP:9090;lr>
Max-Forwards: 69
From: "12345" <sip:12...@asterisk_ip>;tag=9ZoibFKLQySD6Qop2y.CgFNJshsdHlSf
To: "12345" <sip:12...@asterisk_ip>
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61365 REGISTER
Contact: "12345" <sip:12...@192.168.3.6:7160>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Content-Length: 0
P-hint: outbound
<------------->
--- (14 headers 0 lines) ---
Sending to Proxy_IP : 9090 (no NAT)
[Dec 14 21:28:52] NOTICE[5680]: chan_sip.c:9930 __set_address_from_contact: ''
is not a valid SIP contact (missing sip:) trying to use anyway
[Dec 14 21:28:52] WARNING[5680]: chan_sip.c:9938 __set_address_from_contact:
Invalid host name in Contact: (can't resolve in DNS) : ' '
[Dec 14 21:28:52] WARNING[5680]: res_config_mysql.c:386 update_mysql: MySQL
RealTime: Failed to query database. Check debug for more info.
<--- Transmitting (NAT) to Proxy_IP:9090 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK4d68.177229a5.0;received=Proxy_IP
Via: SIP/2.0/UDP
192.168.3.6:7160;received=Nat_IP;rport=62842;branch=z9hG4bKPjTxWqFoP7fl2s1ZB8O.4wLyLKmEnW.2uX
From: "12345" <sip:12...@asterisk_ip>;tag=9ZoibFKLQySD6Qop2y.CgFNJshsdHlSf
To: "12345" <sip:12...@asterisk_ip>;tag=as4ea3ade8
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61365 REGISTER
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="27fcf69d"
Content-Length: 0
<------------>
Scheduling destruction of SIP dialog 'L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP' in
32000 ms (Method: REGISTER)
ser15*CLI>
<--- SIP read from UDP://Proxy_IP:9090 --->
REGISTER sip:Asterisk_IP:5060 SIP/2.0
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK1d68.dd512264.0
Via: SIP/2.0/UDP
192.168.3.6:7160;received=Nat_IP;rport=62842;branch=z9hG4bKPjW7Dgg9CHGy-.oCxGV8DI5MibcvdUu-Su
Route: <sip:Proxy_IP:9090;lr>
Max-Forwards: 69
From: "12345" <sip:12...@asterisk_ip>;tag=9ZoibFKLQySD6Qop2y.CgFNJshsdHlSf
To: "12345" <sip:12...@asterisk_ip>
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61366 REGISTER
Contact: "12345" <sip:12...@192.168.3.6:7160>
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Authorization: Digest username="12345", realm="asterisk", nonce="27fcf69d",
uri="sip:Asterisk_IP:5060", response="cf41f33d7263b3fdf93315e6de3773df",
algorithm=MD5
Content-Length: 0
P-hint: outbound
<------------->
--- (15 headers 0 lines) ---
Sending to Proxy_IP : 9090 (NAT)
[Dec 14 21:28:53] NOTICE[5680]: chan_sip.c:9930 __set_address_from_contact: ''
is not a valid SIP contact (missing sip:) trying to use anyway
[Dec 14 21:28:53] WARNING[5680]: chan_sip.c:9938 __set_address_from_contact:
Invalid host name in Contact: (can't resolve in DNS) : ' '
[Dec 14 21:28:53] WARNING[5680]: res_config_mysql.c:386 update_mysql: MySQL
RealTime: Failed to query database. Check debug for more info.
-- Registered SIP '12345' at Proxy_IP port 9090
[Dec 14 21:28:53] WARNING[5680]: res_config_mysql.c:386 update_mysql: MySQL
RealTime: Failed to query database. Check debug for more info.
<--- Transmitting (NAT) to Proxy_IP:9090 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK1d68.dd512264.0;received=Proxy_IP
Via: SIP/2.0/UDP
192.168.3.6:7160;received=Nat_IP;rport=62842;branch=z9hG4bKPjW7Dgg9CHGy-.oCxGV8DI5MibcvdUu-Su
From: "12345" <sip:12...@asterisk_ip>;tag=9ZoibFKLQySD6Qop2y.CgFNJshsdHlSf
To: "12345" <sip:12...@asterisk_ip>;tag=as4ea3ade8
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61366 REGISTER
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Expires: 300
Contact: <sip:12...@192.168.3.6:7160>;expires=300
Date: Wed, 15 Dec 2010 02:28:53 GMT
Content-Length: 0
<------------>
Scheduling destruction of SIP dialog 'L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP' in
32000 ms (Method: REGISTER)
ser15*CLI>
<--- SIP read from UDP://Proxy_IP:9090 --->
REGISTER sip:Asterisk_IP:5060 SIP/2.0
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK2d68.c161162.0
Via: SIP/2.0/UDP
Nat_IP:62842;rport=62842;branch=z9hG4bKPji3A-cUeY7zX.9wsQSPbIrGiMGx0QLCJ7
Route: <sip:Proxy_IP:9090;lr>
Max-Forwards: 69
From: "12345" <sip:12...@asterisk_ip>;tag=ZXAMq2YToNldiXm9WqE9Kl4kKW9EPYW0
To: "12345" <sip:12...@asterisk_ip>
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61367 REGISTER
Contact: <sip:12...@nat_ip:62842;transport=UDP>
Contact: "12345" <sip:12...@192.168.3.6:7160>;expires=0
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Content-Length: 0
P-hint: outbound
<------------->
--- (15 headers 0 lines) ---
Sending to Proxy_IP : 9090 (NAT)
[Dec 14 21:28:53] NOTICE[5680]: chan_sip.c:9930 __set_address_from_contact: ''
is not a valid SIP contact (missing sip:) trying to use anyway
[Dec 14 21:28:53] WARNING[5680]: chan_sip.c:9938 __set_address_from_contact:
Invalid host name in Contact: (can't resolve in DNS) : ' '
[Dec 14 21:28:53] WARNING[5680]: res_config_mysql.c:386 update_mysql: MySQL
RealTime: Failed to query database. Check debug for more info.
<--- Transmitting (NAT) to Proxy_IP:9090 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK2d68.c161162.0;received=Proxy_IP
Via: SIP/2.0/UDP
Nat_IP:62842;rport=62842;branch=z9hG4bKPji3A-cUeY7zX.9wsQSPbIrGiMGx0QLCJ7
From: "12345" <sip:12...@asterisk_ip>;tag=ZXAMq2YToNldiXm9WqE9Kl4kKW9EPYW0
To: "12345" <sip:12...@asterisk_ip>;tag=as4ea3ade8
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61367 REGISTER
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="282afcbc"
Content-Length: 0
<------------>
Scheduling destruction of SIP dialog 'L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP' in
32000 ms (Method: REGISTER)
ser15*CLI>
<--- SIP read from UDP://Proxy_IP:9090 --->
REGISTER sip:Asterisk_IP:5060 SIP/2.0
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK0e68.9a4d6561.0
Via: SIP/2.0/UDP
Nat_IP:62842;rport=62842;branch=z9hG4bKPjhIuLN7GZhdCBLmTIdv05eRNc9k1zi7VE
Route: <sip:Proxy_IP:9090;lr>
Max-Forwards: 69
From: "12345" <sip:12...@asterisk_ip>;tag=ZXAMq2YToNldiXm9WqE9Kl4kKW9EPYW0
To: "12345" <sip:12...@asterisk_ip>
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61368 REGISTER
Contact: <sip:12...@nat_ip:62842;transport=UDP>
Contact: "12345" <sip:12...@192.168.3.6:7160>;expires=0
Expires: 300
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY, REFER,
MESSAGE, OPTIONS
Authorization: Digest username="12345", realm="asterisk", nonce="282afcbc",
uri="sip:Asterisk_IP:5060", response="70bf0514c5e47ba2a4fef92628b64bca",
algorithm=MD5
Content-Length: 0
P-hint: outbound
<------------->
--- (16 headers 0 lines) ---
Sending to Proxy_IP : 9090 (NAT)
[Dec 14 21:28:53] NOTICE[5680]: chan_sip.c:9930 __set_address_from_contact: ''
is not a valid SIP contact (missing sip:) trying to use anyway
[Dec 14 21:28:53] WARNING[5680]: chan_sip.c:9938 __set_address_from_contact:
Invalid host name in Contact: (can't resolve in DNS) : ' '
[Dec 14 21:28:53] WARNING[5680]: res_config_mysql.c:386 update_mysql: MySQL
RealTime: Failed to query database. Check debug for more info.
-- Registered SIP '12345' at Proxy_IP port 9090
[Dec 14 21:28:53] WARNING[5680]: res_config_mysql.c:386 update_mysql: MySQL
RealTime: Failed to query database. Check debug for more info.
<--- Transmitting (NAT) to Proxy_IP:9090 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP Proxy_IP:9090;branch=z9hG4bK0e68.9a4d6561.0;received=Proxy_IP
Via: SIP/2.0/UDP
Nat_IP:62842;rport=62842;branch=z9hG4bKPjhIuLN7GZhdCBLmTIdv05eRNc9k1zi7VE
From: "12345" <sip:12...@asterisk_ip>;tag=ZXAMq2YToNldiXm9WqE9Kl4kKW9EPYW0
To: "12345" <sip:12...@asterisk_ip>;tag=as4ea3ade8
Call-ID: L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP
CSeq: 61368 REGISTER
User-Agent: Asterisk PBX 1.6.0.5
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces, timer
Expires: 300
Contact: <sip:12...@nat_ip:62842;transport=UDP>;expires=300
Date: Wed, 15 Dec 2010 02:28:53 GMT
Content-Length: 0
<------------>
Scheduling destruction of SIP dialog 'L27qeLd87ekVYu6VDUiJsG4iRAHTiBFP' in
32000 ms (Method: REGISTER)
Really destroying SIP dialog '1o-UnqLhb-j4dSzDzHThXhF0uE-nQu4Z' Method: REGISTER_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
