Hello everyone,
I’m using Asterisk 1.8.17.0 on a CentOS 6.
Several days ago we started to have problems with one of our sip accounts. We have a phone with number 200 which started to fail on authentication to the PBX. We didn’t changed anything and if 200 tries to dial it gets a Forbidden message. However if I dial 200 I can reach it and after that 200 can dial successfully. I even tried to change the password several times but the problem persists. We also tried to change the phone and the problem is still here. I’ve just tried to restart the whole server and we didn’t had luck neither. I’ve also checked sip.conf with hex editor to search for broken termination symbols but it looked OK. I don’t know where to look and I’m sure it’s not a misspelled password.
These are the configuration and debug info:
[root@pbx ~]# asterisk -x ‘sip show peer 200’
[b]pbx*CLI> sip set debug peer 200[/b]
* Name : 200
Secret : <Set>
MD5Secret : <Not set>
Remote Secret: <Not set>
Context : from-internal
Subscr.Cont. : <Not set>
Language :
AMA flags : Unknown
Transfer mode: open
CallingPres : Presentation Allowed, Not Screened
Callgroup : 63
Pickupgroup : 63
MOH Suggest : default
Mailbox : 200
VM Extension : asterisk
LastMsgsSent : 0/0
Call limit : 1000
Max forwards : 0
Dynamic : Yes
Callerid : "Margi" <200>
MaxCallBR : 384 kbps
Expire : 292
Insecure : no
Force rport : Yes
ACL : No
DirectMedACL : No
T.38 support : Yes
T.38 EC mode : FEC
T.38 MaxDtgrm: -1
DirectMedia : No
PromiscRedir : No
User=Phone : No
Video Support: Yes
Text Support : No
Ign SDP ver : No
Trust RPID : Yes
Send RPID : Yes
Subscriptions: Yes
Overlap dial : Yes
DTMFmode : auto
Timer T1 : 500
Timer B : 32000
ToHost :
Addr->IP : 85.91.139.50:11471
Defaddr->IP : (null)
Prim.Transp. : UDP
Allowed.Trsp : UDP
Def. Username: 200
SIP Options : (none)
Codecs : 0x80030c7fffff (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719)
Codec Order : (alaw:20,ulaw:20,gsm:20,g726:20)
Auto-Framing : No
Status : OK (75 ms)
Useragent : Hanlong Unicorn4102M V1.0.1.59
Reg. Contact : sip:200@192.168.0.33:11471;transport=UDP
Qualify Freq : 60000 ms
Sess-Timers : Accept
Sess-Refresh : uas
Sess-Expires : 1800 secs
Min-Sess : 90 secs
RTP Engine : asterisk
Parkinglot :
Use Reason : No
Encryption : Nosip set debug peer 200
[code][2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27]
<— SIP read from UDP:85.91.139.50:11471 —>
REGISTER sip:pbx.tecosys.bg:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK52451d7a
From: “Margi” sip:200@pbx.tecosys.bg;tag=74e7f3ecb70fa626
To: “Margi” sip:200@pbx.tecosys.bg
Call-ID: 9266cf6b9fa3cdca@192.168.1.156
CSeq: 7 REGISTER
Contact: sip:200@192.168.0.33:11471;transport=UDP
Max-Forwards: 70
Supported: path
User-Agent: Hanlong Unicorn4102M V1.0.1.59
Expires: 300
Allow: INVITE, ACK, UPDATE, INFO, CANCEL, BYE, OPTIONS, REFER, SUBSCRIBE, NOTIFY, MESSAGE
Content-Length: 0
<------------->
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27] — (13 headers 0 lines) —
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27] Sending to 85.91.139.50:11471 (NAT)
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27]
<— Transmitting (NAT) to 85.91.139.50:11471 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK52451d7a;received=85.91.139.50;rport=11471
From: “Margi” sip:200@pbx.tecosys.bg;tag=74e7f3ecb70fa626
To: “Margi” sip:200@pbx.tecosys.bg;tag=as093a63c8
Call-ID: 9266cf6b9fa3cdca@192.168.1.156
CSeq: 7 REGISTER
Server: Asterisk PBX 1.8.17.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="1c6bd6e5"
Content-Length: 0
<------------>
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27] Scheduling destruction of SIP dialog ‘9266cf6b9fa3cdca@192.168.1.156’ in 32000 ms (Method: REGISTER)
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27]
<— SIP read from UDP:85.91.139.50:11471 —>
REGISTER sip:pbx.tecosys.bg:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK902fe373
From: “Margi” sip:200@pbx.tecosys.bg;tag=74e7f3ecb70fa626
To: “Margi” sip:200@pbx.tecosys.bg
Call-ID: 9266cf6b9fa3cdca@192.168.1.156
CSeq: 8 REGISTER
Contact: sip:200@192.168.0.33:11471;transport=UDP
Authorization: Digest username=“200”, realm=“asterisk”, nonce=“1c6bd6e5”, uri=“sip:pbx.tecosys.bg:5060”, response=“b97db119ac66f3b616f5e40899935317”, algorithm=MD5
Max-Forwards: 70
Supported: path
User-Agent: Hanlong Unicorn4102M V1.0.1.59
Expires: 300
Allow: INVITE, ACK, UPDATE, INFO, CANCEL, BYE, OPTIONS, REFER, SUBSCRIBE, NOTIFY, MESSAGE
Content-Length: 0
<------------->
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27] — (14 headers 0 lines) —
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27] Sending to 85.91.139.50:11471 (NAT)
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27]
<— Transmitting (NAT) to 85.91.139.50:11471 —>
SIP/2.0 403 Forbidden (Bad auth)
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK902fe373;received=85.91.139.50;rport=11471
From: “Margi” sip:200@pbx.tecosys.bg;tag=74e7f3ecb70fa626
To: “Margi” sip:200@pbx.tecosys.bg;tag=as093a63c8
Call-ID: 9266cf6b9fa3cdca@192.168.1.156
CSeq: 8 REGISTER
Server: Asterisk PBX 1.8.17.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0
<------------>
[2013-08-07 11:48:27] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:27] Scheduling destruction of SIP dialog ‘9266cf6b9fa3cdca@192.168.1.156’ in 32000 ms (Method: REGISTER)
[2013-08-07 11:48:38] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:38]
<— SIP read from UDP:85.91.139.50:11471 —>
<------------->
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47]
<— SIP read from UDP:85.91.139.50:11471 —>
REGISTER sip:pbx.tecosys.bg:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK2450612061
From: “Margi” sip:200@pbx.tecosys.bg;tag=350833cb31362039
To: “Margi” sip:200@pbx.tecosys.bg
Call-ID: 2c1328e696f9c5fd@192.168.1.156
CSeq: 1 REGISTER
Contact: sip:200@192.168.0.33:11471;transport=UDP
Max-Forwards: 70
Supported: path
User-Agent: Hanlong Unicorn4102M V1.0.1.59
Expires: 300
Allow: INVITE, ACK, UPDATE, INFO, CANCEL, BYE, OPTIONS, REFER, SUBSCRIBE, NOTIFY, MESSAGE
Content-Length: 0
<------------->
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47] — (13 headers 0 lines) —
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47] Sending to 85.91.139.50:11471 (NAT)
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47]
<— Transmitting (NAT) to 85.91.139.50:11471 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK2450612061;received=85.91.139.50;rport=11471
From: “Margi” sip:200@pbx.tecosys.bg;tag=350833cb31362039
To: “Margi” sip:200@pbx.tecosys.bg;tag=as7db2f27d
Call-ID: 2c1328e696f9c5fd@192.168.1.156
CSeq: 1 REGISTER
Server: Asterisk PBX 1.8.17.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="35be1d5f"
Content-Length: 0
<------------>
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47] Scheduling destruction of SIP dialog ‘2c1328e696f9c5fd@192.168.1.156’ in 32000 ms (Method: REGISTER)
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47]
<— SIP read from UDP:85.91.139.50:11471 —>
REGISTER sip:pbx.tecosys.bg:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK5318204b
From: “Margi” sip:200@pbx.tecosys.bg;tag=350833cb31362039
To: “Margi” sip:200@pbx.tecosys.bg
Call-ID: 2c1328e696f9c5fd@192.168.1.156
CSeq: 2 REGISTER
Contact: sip:200@192.168.0.33:11471;transport=UDP
Authorization: Digest username=“200”, realm=“asterisk”, nonce=“35be1d5f”, uri=“sip:pbx.tecosys.bg:5060”, response=“d2748de844b1cf2fc192d6640b00f97f”, algorithm=MD5
Max-Forwards: 70
Supported: path
User-Agent: Hanlong Unicorn4102M V1.0.1.59
Expires: 300
Allow: INVITE, ACK, UPDATE, INFO, CANCEL, BYE, OPTIONS, REFER, SUBSCRIBE, NOTIFY, MESSAGE
Content-Length: 0
<------------->
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47] — (14 headers 0 lines) —
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47] Sending to 85.91.139.50:11471 (NAT)
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47] Reliably Transmitting (NAT) to 85.91.139.50:11471:
OPTIONS sip:200@192.168.0.33:11471;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 88.213.204.121:5060;branch=z9hG4bK64317c8c;rport
Max-Forwards: 70
From: “Asterisk” sip:Asterisk@88.213.204.121;tag=as242de675
To: sip:200@192.168.0.33:11471;transport=UDP
Contact: sip:Asterisk@88.213.204.121:5060
Call-ID: 1d31573b57a3f56e06cb392673c8adc1@88.213.204.121:5060
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX 1.8.17.0
Date: Wed, 07 Aug 2013 08:48:47 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0
[2013-08-07 11:48:47] VERBOSE[1672] chan_sip.c: [2013-08-07 11:48:47]
<— Transmitting (NAT) to 85.91.139.50:11471 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.0.33:11471;branch=z9hG4bK5318204b;received=85.91.139.50;rport=11471
From: “Margi” sip:200@pbx.tecosys.bg;tag=350833cb31362039
To: “Margi” sip:200@pbx.tecosys.bg;tag=as7db2f27d
Call-ID: 2c1328e696f9c5fd@192.168.1.156
CSeq: 2 REGISTER
Server: Asterisk PBX 1.8.17.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Expires: 300
Contact: sip:200@192.168.0.33:11471;transport=UDP;expires=300
Date: Wed, 07 Aug 2013 08:48:47 GMT
Content-Length: 0
<------------>[/code]
You can see that first time Asterisk returns “403 Forbidden (Bad auth)” packet, immediately after that the client retries to register and Asterisk returns successfully OPTIONS packet.
It’s a mystery for me, so do you know what can cause that?
