[Ekiga-list] security check failed
Thomas Schiex
Thomas.Schiex at free.fr
Wed Apr 18 21:16:01 UTC 2007
I tried to reuse Ekiga SIP after a period of quietness in this area
(Ekiga worked fine one year ago). I used my SIP account (provided by my
ISP, free.fr). This is the only account I have configured.
The call is not initiated and I instead get a "Security check failed"
message. This was using EKiga 2.0.3.
1) I cross checked (retyped) the Registrar, user, password and
authentication id.
Still fails
2) I tested the SIP account using Twinkle and XLite
Both worked fine
3) I rechecked the SIP account configuration in Ekiga for safety:
Failed again
4) I upgraded Ekiga to 2.0.9 (using saillard ubuntu repository)
Still fails with the same message (appears more shortly)
5) I stopped my (iptable) firewall for a moment (DMZ machine), retried:
failure (STUN NAT with restricted port). Tried redoing NAT detection in
Ekiga, shifted to Cone NAT:
Still fails with the same message
4) I restarted my firewall and redid NAT detection (went back to
restricted port). I tried an ekiga -d4. Ekiga seems to register the SIP
account fine but the call itself fails... again I put part of it below.
Any idea ? I'd rather use Ekiga than Twinkle.
Thomas
----
2007/04/18 23:02:22.387 0:36.636 SIP Transport:89fa3d0 SIP
Transaction 3 SUBSCRIBE completed.
[...]
2007/04/18 23:03:18.871 1:33.120 GMURLHandler:08a97260 PCSS
Outgoing call routed to sip:0561285428 at freephonie.net for
Call[1]-EP<pc>[Default]
2007/04/18 23:03:18.872 1:33.121 GMURLHandler:08a97260 Call
OnSetUp Call[1]-EP<pc>[Default]
2007/04/18 23:03:18.872 1:33.121 GMURLHandler:08a97260 SIP
SetUpConnection: <sip:0561285428 at freephonie.net>
2007/04/18 23:03:18.998 1:33.247 GMURLHandler:08a97260 OpalUDP
Binding to interface: 192.168.0.1:32819
2007/04/18 23:03:18.998 1:33.247 GMURLHandler:08a97260 SIP
Created transport udp$0.0.0.0<if=udp$192.168.0.1:32819>
2007/04/18 23:03:18.999 1:33.248 GMURLHandler:08a97260 OpalUDP
Started connect to 212.27.52.5:5060
2007/04/18 23:03:19.079 1:33.328 GMURLHandler:08a97260 OpalUDP
STUN created socket: 82.254.75.27:5065
2007/04/18 23:03:19.081 1:33.330 GMURLHandler:08a97260 SIP
Transaction 1 INVITE created.
2007/04/18 23:03:19.081 1:33.330 GMURLHandler:08a97260 Call
CanDoMediaBypass
Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol] session 1
2007/04/18 23:03:19.082 1:33.331 GMURLHandler:08a97260 OpalMan
IsMediaBypassPossible: session 1
2007/04/18 23:03:19.082 1:33.331 GMURLHandler:08a97260 SIP
IsMediaBypassPossible: session 1
2007/04/18 23:03:19.082 1:33.331 GMURLHandler:08a97260 OpalCon
IsMediaBypassPossible: default returns FALSE
2007/04/18 23:03:19.083 1:33.332 SIP Transport:8ad95f8 SIP
Read thread started.
2007/04/18 23:03:19.083 1:33.332 SIP Transport:8ad95f8 SIP
Waiting for PDU on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
2007/04/18 23:03:20.089 1:34.338 Opal Listener:86c4248 SIP
Unknown method name Cirpack received on udp$212.27.52.5:5060<if=udp
$192.168.0.1:5060>
2007/04/18 23:03:20.089 1:34.338 Opal Listener:86c4248 Opal
Transport clean up on termination
2007/04/18 23:03:20.089 1:34.339 Opal Listener:86c4248 OpalUDP
Close
2007/04/18 23:03:20.090 1:34.339 Opal Listener:86c4248 Listen
Waiting on UDP packet on udp$192.168.0.1:5060
2007/04/18 23:03:24.306 1:38.555 GMURLHandler:08a97260 RTP
STUN could not create RTP/RTCP socket pair; trying to create RTP socket
anyway.
2007/04/18 23:03:24.465 1:38.714 GMURLHandler:08a97260 RTP_UDP
Session 1 created: 82.254.75.27:5066-5067 ssrc=805738867
2007/04/18 23:03:24.465 1:38.714 GMURLHandler:08a97260 RTP
Adding session RTP_UDP
2007/04/18 23:03:24.469 1:38.718 GMURLHandler:08a97260 Call
GetMediaFormats for
Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
SpeexWide-20.6k
GSM-06.10
MS-GSM
SpeexNarrow-8k
G.711-uLaw-64k
G.711-ALaw-64k
G.726-16k
G.726-32k
LPC-10
H.261(QCIF)
H.261(CIF)
YUV420P
RGB32
RGB24
2007/04/18 23:03:24.470 1:38.719 GMURLHandler:08a97260 SIP
Using RTP payload [pt=101] for NTE
2007/04/18 23:03:24.470 1:38.719 GMURLHandler:08a97260 Call
CanDoMediaBypass
Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol] session 2
2007/04/18 23:03:24.470 1:38.719 GMURLHandler:08a97260 OpalMan
IsMediaBypassPossible: session 2
2007/04/18 23:03:24.470 1:38.719 GMURLHandler:08a97260 SIP
IsMediaBypassPossible: session 2
2007/04/18 23:03:24.470 1:38.719 GMURLHandler:08a97260 OpalCon
IsMediaBypassPossible: default returns FALSE
2007/04/18 23:03:24.787 1:39.036 GMURLHandler:08a97260 RTP_UDP
Session 2 created: 82.254.75.27:5006-5007 ssrc=1883152657
2007/04/18 23:03:24.787 1:39.037 GMURLHandler:08a97260 RTP
Adding session RTP_UDP
2007/04/18 23:03:24.792 1:39.041 GMURLHandler:08a97260 Call
GetMediaFormats for
Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
SpeexWide-20.6k
GSM-06.10
MS-GSM
SpeexNarrow-8k
G.711-uLaw-64k
G.711-ALaw-64k
G.726-16k
G.726-32k
LPC-10
H.261(QCIF)
H.261(CIF)
YUV420P
RGB32
RGB24
2007/04/18 23:03:24.792 1:39.041 GMURLHandler:08a97260 SIP
No authentication information present
2007/04/18 23:03:24.793 1:39.042 GMURLHandler:08a97260 SIP
Sending PDU on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
INVITE sip:0561285428 at freephonie.net SIP/2.0
Date: Wed, 18 Apr 2007 21:03:19 GMT
CSeq: 1 INVITE
Via: SIP/2.0/UDP
82.254.75.27:5065;branch=z9hG4bK487218e7-5dec-db11-9736-0026540c8cec;rport
User-Agent: Ekiga/2.0.9
From: "Thomas Schiex"
<sip:0951082848 at freephonie.net>;tag=98d7e5e6-5dec-db11-9736-0026540c8cec
Call-ID: 84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol
To: <sip:0561285428 at freephonie.net>
Contact: <sip:0951082848 at 82.254.75.27:5065;transport=udp>
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,REFER,MESSAGE
Content-Type: application/sdp
Content-Length: 468
Max-Forwards: 70
v=0
o=- 1176930204 1176930204 IN IP4 82.254.75.27
s=Opal SIP Session
c=IN IP4 82.254.75.27
t=0 0
m=audio 5066 RTP/AVP 114 3 107 110 0 8 106 2 7 101
a=rtpmap:114 SPEEX/16000
a=rtpmap:3 GSM/8000
a=rtpmap:107 MS-GSM/8000
a=rtpmap:110 SPEEX/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 G726-16k/8000
a=rtpmap:2 G721/8000
a=rtpmap:7 LPC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
m=video 5006 RTP/AVP 31
a=rtpmap:31 H261/90000
2007/04/18 23:03:24.793 1:39.042 GMURLHandler:08a97260
SetUpCall succeeded
2007/04/18 23:03:24.860 1:39.109 SIP Transport:8ad95f8 SIP
PDU Received on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
SIP/2.0 100 Trying
CSeq: 1 INVITE
Via: SIP/2.0/UDP
82.254.75.27:5065;received=82.254.75.27;rport=5065;branch=z9hG4bK487218e7-5dec-db11-9736-0026540c8cec
From: "Thomas Schiex"
<sip:0951082848 at freephonie.net>;tag=98d7e5e6-5dec-db11-9736-0026540c8cec
Call-ID: 84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol
To: <sip:0561285428 at freephonie.net>
Content-Length: 0
2007/04/18 23:03:24.861 1:39.111 SIP Transport:8ad95f8 OpalUDP
Ended connect, selecting 82.254.75.27:5065
2007/04/18 23:03:24.862 1:39.111 SIP Transport:8ad95f8 SIP
Queueing PDU: 1 INVITE <100>
2007/04/18 23:03:24.862 1:39.111 SIP Transport:8ad95f8 SIP
Waiting for PDU on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
2007/04/18 23:03:24.863 1:39.112 SIP Transport:8ad95f8 SIP
PDU Received on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
SIP/2.0 403 not registered
CSeq: 1 INVITE
Via: SIP/2.0/UDP
82.254.75.27:5065;received=82.254.75.27;rport=5065;branch=z9hG4bK487218e7-5dec-db11-9736-0026540c8cec
From: "Thomas Schiex"
<sip:0951082848 at freephonie.net>;tag=98d7e5e6-5dec-db11-9736-0026540c8cec
Call-ID: 84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol
To: <sip:0561285428 at freephonie.net>;tag=00-32540-00273f2b-57fd4bd10
Content-Length: 0
2007/04/18 23:03:24.864 1:39.113 SIP Transport:8ad95f8 SIP
Queueing PDU: 1 INVITE <403>
2007/04/18 23:03:24.864 1:39.113 SIP Transport:8ad95f8 SIP
Waiting for PDU on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
2007/04/18 23:03:24.864 1:39.113 SIP Handler:8af8fb0 SIP
PDU handler thread started.
2007/04/18 23:03:24.865 1:39.114 SIP Handler:8af8fb0 SIP
Awaiting next PDU.
2007/04/18 23:03:24.865 1:39.114 SIP Handler:8af8fb0 SIP
Handling PDU 1 INVITE <100>
2007/04/18 23:03:24.865 1:39.114 SIP Handler:8af8fb0 SIP
Transaction 1 INVITE proceeding.
2007/04/18 23:03:24.866 1:39.115 SIP Handler:8af8fb0 SIP
Received Trying response
2007/04/18 23:03:24.866 1:39.115 SIP Handler:8af8fb0 SIP
Awaiting next PDU.
2007/04/18 23:03:24.866 1:39.115 SIP Handler:8af8fb0 SIP
Handling PDU 1 INVITE <403>
2007/04/18 23:03:24.867 1:39.116 SIP Handler:8af8fb0 SIP
Transaction 1 INVITE completed.
2007/04/18 23:03:24.868 1:39.117 SIP Handler:8af8fb0 SIP
Sending PDU on udp$212.27.52.5:5060<if=udp$82.254.75.27:5065>
ACK sip:0561285428 at freephonie.net SIP/2.0
CSeq: 1 ACK
Via: SIP/2.0/UDP
82.254.75.27:5065;branch=z9hG4bK487218e7-5dec-db11-9736-0026540c8cec;rport
From: "Thomas Schiex"
<sip:0951082848 at freephonie.net>;tag=98d7e5e6-5dec-db11-9736-0026540c8cec
Call-ID: 84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol
To: <sip:0561285428 at freephonie.net>;tag=00-32540-00273f2b-57fd4bd10
Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,NOTIFY,REFER,MESSAGE
Content-Length: 0
Max-Forwards: 70
2007/04/18 23:03:24.869 1:39.118 SIP Handler:8af8fb0 OpalCon
Releasing Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
2007/04/18 23:03:24.869 1:39.118 SIP Handler:8af8fb0 OpalCon
Call end reason for 84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol set to
EndedBySecurityDenial
2007/04/18 23:03:24.869 1:39.121 SIP Handler:8af8fb0 OpalCon
SetPhase from UninitialisedPhase to ReleasingPhase
2007/04/18 23:03:24.873 1:39.122 SIP Handler:8af8fb0 SIP
Awaiting next PDU.
2007/04/18 23:03:24.873 1:39.122 OnRelease:8a92320 SIP
OnReleased:
Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol], phase =
ReleasingPhase
2007/04/18 23:03:24.873 1:39.123 OnRelease:8a92320 OpalCon
SetPhase from ReleasingPhase to ReleasingPhase
2007/04/18 23:03:24.875 1:39.124 OnRelease:8a92320 SIP
Cancelling transaction 0 of 1
2007/04/18 23:03:24.875 1:39.124 OnRelease:8a92320 SIP
Could not cancel transaction 0
2007/04/18 23:03:24.875 1:39.124 OnRelease:8a92320 OpalCon
Media stream threads closed.
2007/04/18 23:03:24.875 1:39.124 OnRelease:8a92320 OpalCon
SetPhase from ReleasingPhase to ReleasedPhase
2007/04/18 23:03:24.876 1:39.125 SIP Handler:8af8fb0 SIP
PDU handler thread finished.
2007/04/18 23:03:24.876 1:39.125 OnRelease:8a92320 Opal
Transport clean up on termination
2007/04/18 23:03:24.876 1:39.125 OnRelease:8a92320 OpalUDP
Close
2007/04/18 23:03:24.876 1:39.125 OnRelease:8a92320 Opal
Transport Close
2007/04/18 23:03:24.877 1:39.126 SIP Transport:8ad95f8 SIP
Read thread finished.
2007/04/18 23:03:24.877 1:39.126 OnRelease:8a92320 OpalCon
OnReleased Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
2007/04/18 23:03:24.877 1:39.126 OnRelease:8a92320 OpalCon
Media stream threads closed.
2007/04/18 23:03:24.878 1:39.127 OnRelease:8a92320
GMSIPEndpoint SIP connection released
2007/04/18 23:03:24.878 1:39.127 OnRelease:8a92320 OpalEP
OnReleased Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
2007/04/18 23:03:25.021 1:39.270 OnRelease:8a92320
GMManager Will release the connection
2007/04/18 23:03:25.021 1:39.271 OnRelease:8a92320 OpalMan
OnReleased Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
2007/04/18 23:03:25.022 1:39.271 OnRelease:8a92320 Call
OnReleased Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
2007/04/18 23:03:25.022 1:39.271 OnRelease:8a92320 OpalCon
Releasing Call[1]-EP<pc>[Default]
2007/04/18 23:03:25.023 1:39.272 OnRelease:8a92320 OpalCon
Call end reason for Default set to EndedBySecurityDenial
2007/04/18 23:03:25.023 1:39.272 OnRelease:8a92320 OpalCon
SetPhase from SetUpPhase to ReleasingPhase
2007/04/18 23:03:25.023 1:39.273 OnRelease:8a92320 SIP
Transaction 1 INVITE aborted.
2007/04/18 23:03:25.024 1:39.273 OnRelease:8a92320 SIP
Transaction 1 INVITE destroyed.
2007/04/18 23:03:25.024 1:39.273 OnRelease:8a92320 OpalCon
OnRelease thread completed for
84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol
2007/04/18 23:03:25.025 1:39.274 OnRelease:8a23848 OpalCon
OnReleased Call[1]-EP<pc>[Default]
2007/04/18 23:03:25.025 1:39.274 OnRelease:8a23848 OpalCon
Media stream threads closed.
2007/04/18 23:03:25.032 1:39.284 OnRelease:8a23848
GMPCSSEndpoint PCSS connection released
2007/04/18 23:03:25.035 1:39.284 OnRelease:8a23848 OpalEP
OnReleased Call[1]-EP<pc>[Default]
2007/04/18 23:03:25.035 1:39.284 OnRelease:8a23848
GMManager Will release the connection
2007/04/18 23:03:25.036 1:39.285 OnRelease:8a23848 OpalMan
OnReleased Call[1]-EP<pc>[Default]
2007/04/18 23:03:25.036 1:39.285 OnRelease:8a23848 Call
OnReleased Call[1]-EP<pc>[Default]
2007/04/18 23:03:25.794 1:40.043 OpalGarbage Opal
Transport clean up on termination
2007/04/18 23:03:25.794 1:40.043 OpalGarbage OpalUDP
Close
2007/04/18 23:03:25.794 1:40.043 OpalGarbage Opal
Transport Close
2007/04/18 23:03:25.794 1:40.043 OpalGarbage SIP
Deleted connection.
2007/04/18 23:03:25.794 1:40.043 OpalGarbage OpalCon
Connection Call[1]-EP<sip>[84d2e5e6-5dec-db11-9736-0026540c8cec at pomerol]
destroyed.
2007/04/18 23:03:25.794 1:40.043 OpalGarbage RTP_UDP
Session 1, Shutting down read.
2007/04/18 23:03:25.794 1:40.043 OpalGarbage RTP_UDP
Session 1, Shutting down write.
2007/04/18 23:03:25.795 1:40.044 OpalGarbage RTP_UDP
Session 2, Shutting down read.
2007/04/18 23:03:25.795 1:40.044 OpalGarbage RTP_UDP
Session 2, Shutting down write.
2007/04/18 23:03:27.215 1:41.465 Opal Listener:86c4248 OpalUDP
Pre-bound to interface: 192.168.0.1:5060
2007/04/18 23:03:27.216 1:41.465 Opal Listener:86c4248 SIP
Waiting for PDU on udp$0.0.0.0<if=udp$192.168.0.1:5060>
2007/04/18 23:03:31.241 1:45.491 OnRelease:8a23848 OpalCon
OnRelease thread completed for Default
2007/04/18 23:03:31.794 1:46.043 OpalGarbage PCSS
Deleted PC sound system connection.
2007/04/18 23:03:31.794 1:46.043 OpalGarbage OpalCon
Connection Call[1]-EP<pc>[Default] destroyed.
2007/04/18 23:03:32.270 1:46.519 Opal Listener:86c4248 SIP
Unknown method name Cirpack received on udp$212.27.52.5:5060<if=udp
$192.168.0.1:5060>
2007/04/18 23:03:32.270 1:46.519 Opal Listener:86c4248 Opal
Transport clean up on termination
2007/04/18 23:03:32.270 1:46.519 Opal Listener:86c4248 OpalUDP
Close
More information about the ekiga-list
mailing list