Bug 616197 – Wrongly assume the REGISTER authentication is successful and fail to REGISTER

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 616197 - Wrongly assume the REGISTER authentication is successful and fail to REGISTER


Summary:	Wrongly assume the REGISTER authentication is successful and fail to REGISTER


Status:	RESOLVED NOTABUG

Product:	ekiga
Classification:	Applications
Component:	OPAL
Version:	3.2.x
Hardware:	Other Linux

Importance:	Normal normal
Target Milestone:	---
Assigned To:	Ekiga maintainers
QA Contact:	Ekiga maintainers

URL:
Whiteboard:

Depends on:
Blocks:

Reported:	2010-04-19 16:40 UTC by Yannick
Modified:	2010-04-19 19:27 UTC

See Also:
GNOME target:	---
GNOME version:	---

Description Yannick 2010-04-19 16:40:30 UTC

Hi,

Pushing here this bug:
https://bugs.launchpad.net/ubuntu/+source/ekiga/+bug/332543/comments/26

Debug log:
http://launchpadlibrarian.net/44828521/output.txt

IMHO relevant part of this log:

2010/04/19 10:56:11.530	  0:08.440	Opal Liste...0xb73beb70	SIP	PDU received: rem=udp$86.64.162.35:5060,local=udp$24.78.44.252:5060,if=192.168.0.111%eth1
SIP/2.0 401 Unauthorized
CSeq: 2 REGISTER
Via: SIP/2.0/UDP 24.78.44.252:5060;branch=z9hG4bK2a1269be-394a-df11-8298-00265e153a08;rport=5060
Server: Kamailio (1.5.3-notls (i386/linux))
From: <sip:david.j.w@ekiga.net>;tag=b0dd21be-394a-df11-8298-00265e153a08
Call-ID: ceb521be-394a-df11-8298-00265e153a08@david-netbook
To: <sip:david.j.w@ekiga.net>;tag=c64e1f832a41ec1c1f4e5673ac5b80f6.5919
Content-Length: 0
WWW-Authenticate: Digest realm="ekiga.net", nonce="4bcc7d3800016de59444bfda8a963376f3ecd01dcfebe82f"


2010/04/19 10:56:11.533	  0:08.443	Opal Liste...0xb73beb70	SIP	Queueing PDU "2 REGISTER <401>", transaction=z9hG4bK2a1269be-394a-df11-8298-00265e153a08, token=ceb521be-394a-df11-8298-00265e153a08@david-netbook
2010/04/19 10:56:11.534	  0:08.444	        Pool:0xb733cb70	SIP	Handling PDU "2 REGISTER <401>" for transaction=z9hG4bK2a1269be-394a-df11-8298-00265e153a08
2010/04/19 10:56:11.535	  0:08.445	        Pool:0xb733cb70	SIP	REGISTER transaction id=z9hG4bK2a1269be-394a-df11-8298-00265e153a08 completed.
2010/04/19 10:56:11.537	  0:08.446	Opal Liste...0xb73beb70	Opal	Transport clean up on termination
2010/04/19 10:56:11.538	  0:08.447	Opal Liste...0xb73beb70	Opal	Transport Close
2010/04/19 10:56:11.539	  0:08.448	        Pool:0xb733cb70	OpalUDP	Setting interface to 192.168.0.111%eth1
2010/04/19 10:56:11.540	  0:08.450	        Pool:0xb733cb70	SIP	Received Authentication Required response
2010/04/19 10:56:11.542	  0:08.451	        Pool:0xb733cb70	SIP	Found auth info for realm ekiga.net
2010/04/19 10:56:11.543	  0:08.453	        Pool:0xb733cb70	SIP	Authentication already performed using current credentials, not trying again.
2010/04/19 10:56:11.541	  0:08.451	Opal Liste...0xb73beb70	Opal	Deleted transport udp$86.64.162.35:5060<if=udp$24.78.44.252:5060>
2010/04/19 10:56:11.547	  0:08.457	        Pool:0xb733cb70	SIP	Handled PDU "2 REGISTER <401>"
2010/04/19 10:56:12.348	  0:09.257	 Housekeeper:0xb73ffb70	SIP	Set state Terminated_Success for REGISTER transaction id=z9hG4bKa66e3bbe-394a-df11-8298-00265e153a08
2010/04/19 10:56:12.546	  0:09.456	 Housekeeper:0xb73ffb70	SIP	Set state Terminated_Success for REGISTER transaction id=z9hG4bK2a1269be-394a-df11-8298-00265e153a08
2010/04/19 10:56:13.088	  0:09.998	Opal Garbage:0xb7595b70	SIP	Transaction id=z9hG4bK2a1269be-394a-df11-8298-00265e153a08 destroyed.
2010/04/19 10:56:13.090	  0:09.999	Opal Garbage:0xb7595b70	SIP	Transaction id=z9hG4bKa66e3bbe-394a-df11-8298-00265e153a08 destroyed.

Instead of a respond using the nounce in the 401 REGISTER from Ekiga.NET ro complete the REGISTER transaction, Ekiga 3.2.6 wrongly assume the REGISTER transaction is succesfull according to the log.

Best regards,
Yannick

Comment 1 Damien Sandras 2010-04-19 17:17:50 UTC

"Authentication already performed using current credentials, not trying again."
is a hint to tell it already tried to register with those credentials.

Comment 2 Yannick 2010-04-19 17:32:41 UTC

Hi Damien,

Here is the full sequence, do you consider it as normal?

2010/04/19 10:56:11.046	  0:07.956	  subscriber:0xb532fb70	SIP	Sending PDU (549 bytes) to: rem=udp$86.64.162.35:5060,local=udp$24.78.44.252:5060,if=192.168.0.111%eth1
REGISTER sip:ekiga.net SIP/2.0
CSeq: 1 REGISTER
Via: SIP/2.0/UDP 24.78.44.252:5060;branch=z9hG4bKa66e3bbe-394a-df11-8298-00265e153a08;rport
User-Agent: Ekiga/3.2.6
From: <sip:david.j.w@ekiga.net>;tag=b0dd21be-394a-df11-8298-00265e153a08
Call-ID: ceb521be-394a-df11-8298-00265e153a08@david-netbook
To: <sip:david.j.w@ekiga.net>
Contact: <sip:david.j.w@24.78.44.252>;q=1, <sip:david.j.w@192.168.0.111>;q=0.500
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
Expires: 3600
Content-Length: 0
Max-Forwards: 70


2010/04/19 10:56:11.235	  0:08.145	Opal Liste...0xb73beb70	SIP	PDU received: rem=udp$86.64.162.35:5060,local=udp$24.78.44.252:5060,if=192.168.0.111%eth1
SIP/2.0 401 Unauthorized
CSeq: 1 REGISTER
Via: SIP/2.0/UDP 24.78.44.252:5060;branch=z9hG4bKa66e3bbe-394a-df11-8298-00265e153a08;rport=5060
Server: Kamailio (1.5.3-notls (i386/linux))
From: <sip:david.j.w@ekiga.net>;tag=b0dd21be-394a-df11-8298-00265e153a08
Call-ID: ceb521be-394a-df11-8298-00265e153a08@david-netbook
To: <sip:david.j.w@ekiga.net>;tag=c64e1f832a41ec1c1f4e5673ac5b80f6.b54d
Content-Length: 0
WWW-Authenticate: Digest realm="ekiga.net", nonce="4bcc7d3700016de1b74544150671707de437d6111c6902f5"

2010/04/19 10:56:11.342	  0:08.252	        Pool:0xb733cb70	SIP	Sending PDU (761 bytes) to: rem=udp$86.64.162.35:5060,local=udp$24.78.44.252:5060,if=192.168.0.111%eth1
REGISTER sip:ekiga.net SIP/2.0
CSeq: 2 REGISTER
Via: SIP/2.0/UDP 24.78.44.252:5060;branch=z9hG4bK2a1269be-394a-df11-8298-00265e153a08;rport
User-Agent: Ekiga/3.2.6
Authorization: Digest username="david.j.w@ekiga.net", realm="ekiga.net", nonce="4bcc7d3700016de1b74544150671707de437d6111c6902f5", uri="sip:ekiga.net", algorithm=MD5, response="b3d51ae2f7b65e16b890ae36af7daa16"
From: <sip:david.j.w@ekiga.net>;tag=b0dd21be-394a-df11-8298-00265e153a08
Call-ID: ceb521be-394a-df11-8298-00265e153a08@david-netbook
To: <sip:david.j.w@ekiga.net>
Contact: <sip:david.j.w@24.78.44.252>;q=1, <sip:david.j.w@192.168.0.111>;q=0.500
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
Expires: 3600
Content-Length: 0
Max-Forwards: 70

2010/04/19 10:56:11.530	  0:08.440	Opal Liste...0xb73beb70	SIP	PDU received: rem=udp$86.64.162.35:5060,local=udp$24.78.44.252:5060,if=192.168.0.111%eth1
SIP/2.0 401 Unauthorized
CSeq: 2 REGISTER
Via: SIP/2.0/UDP 24.78.44.252:5060;branch=z9hG4bK2a1269be-394a-df11-8298-00265e153a08;rport=5060
Server: Kamailio (1.5.3-notls (i386/linux))
From: <sip:david.j.w@ekiga.net>;tag=b0dd21be-394a-df11-8298-00265e153a08
Call-ID: ceb521be-394a-df11-8298-00265e153a08@david-netbook
To: <sip:david.j.w@ekiga.net>;tag=c64e1f832a41ec1c1f4e5673ac5b80f6.5919
Content-Length: 0
WWW-Authenticate: Digest realm="ekiga.net", nonce="4bcc7d3800016de59444bfda8a963376f3ecd01dcfebe82f"

2010/04/19 10:56:11.543	  0:08.453	        Pool:0xb733cb70	SIP	Authentication already performed using current credentials, not trying again.

There is no respond from Ekiga 3.2.6 using the nonce...

Best regards,
Yannick

Comment 3 Yannick 2010-04-19 17:36:59 UTC

Hm... maybe I was wrong: it use the nonce but in a "CSeq: 2 REGISTER", I think it should use it as "CSeq: 1 REGISTER", right?

i.e.:
2010/04/19 10:56:11.342      0:08.252            Pool:0xb733cb70    SIP   
Sending PDU (761 bytes) to:
rem=udp$86.64.162.35:5060,local=udp$24.78.44.252:5060,if=192.168.0.111%eth1
REGISTER sip:ekiga.net SIP/2.0
CSeq: 2 REGISTER
Via: SIP/2.0/UDP
24.78.44.252:5060;branch=z9hG4bK2a1269be-394a-df11-8298-00265e153a08;rport
User-Agent: Ekiga/3.2.6
Authorization: Digest username="david.j.w@ekiga.net", realm="ekiga.net",
nonce="4bcc7d3700016de1b74544150671707de437d6111c6902f5", uri="sip:ekiga.net",
algorithm=MD5, response="b3d51ae2f7b65e16b890ae36af7daa16"
From: <sip:david.j.w@ekiga.net>;tag=b0dd21be-394a-df11-8298-00265e153a08
Call-ID: ceb521be-394a-df11-8298-00265e153a08@david-netbook
To: <sip:david.j.w@ekiga.net>
Contact: <sip:david.j.w@24.78.44.252>;q=1,
<sip:david.j.w@192.168.0.111>;q=0.500
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,SUBSCRIBE,NOTIFY,REFER,MESSAGE,INFO,PING
Expires: 3600
Content-Length: 0
Max-Forwards: 70

Comment 4 Damien Sandras 2010-04-19 17:42:18 UTC

Not to my knowledge. I think it is correct.

I think the user's password is simply invalid or contains weird chars.

Comment 5 Yannick 2010-04-19 17:53:57 UTC

HM... that's embarassing: I'm wrong:
"In all of the above cases, the request is retried by creating a new
   request with the appropriate modifications.  This new request
   constitutes a new transaction and SHOULD have the same value of the
   Call-ID, To, and From of the previous request, but the CSeq should
   contain a new sequence number that is one higher than the previous."
8.1.3.5 Processing 4xx Responses

in http://tools.ietf.org/html/rfc3261#section-20.16

I'm digging this deeper...

Comment 6 Yannick 2010-04-19 17:54:59 UTC

I'll try your idea of wrong password...

Comment 7 Yannick 2010-04-19 17:59:28 UTC

Hm... the explanation is simple as:

There is no user "david.j.w" in Ekiga.NET

Sorry for the noise...

Comment 8 Damien Sandras 2010-04-19 19:27:16 UTC

Cool, I like such bugs :-)