Re: [OpenSIPStack] upper registration route problem - authentication fails
Brought to you by:
joegenbaclor
Menu
▾
▴
Re: [OpenSIPStack] upper registration route problem - authentication fails
|
From: OpenSIPStack F. <ope...@op...> - 2008-06-17 01:24:38
|
Hi,
I am unable to replicate this in my box. However, I have a hunch what is causing this for you. You need to help me out understand why it is happening. Can you trace though ProxySession.cxx for me and find the following code block:
void ProxySession::OnFinalResponse( SIPMessage & message )
{
GCVERIFYREF_VOID( "ProxySession::OnFinalResponse" );
SIPMessage response = message;
Via via;
response.GetViaAt( 0, via );
if( GetTransportManager()->IsLocalAddressAndPort( via.GetURI() ) )
response.PopTopVia();
If my hunch is correct, OpenSBC is unable to POP the top-most via of the response because it did not resolve as a local address:port. Can you confirm this? Please add a PTRACE within the if block like so:
if( GetTransportManager()->IsLocalAddressAndPort( via.GetURI() ) )
{
PTRACE( 1, "FATAL!!!! Unable to POP Top-most Via" );
response.PopTopVia();
}
Let me know if it appears in your tests. If you are a developer, it would be nice if you could trace into IsLocalAddressAndPort function and tell me where it fails.
Joegen
> {quote:title=cam100 wrote:}{quote}
> Hi all,
>
>
>
>
>
> I have been searching the forum for hours now but can not find any hint what I' m doing wrong. I' m running OpenSBC in B2B upper registration mode and would like to have my clients registering whith our existing softswitch. I have set up everything according to the tutorials and howto's which can be found in this forum.
>
>
>
>
> The client sends a register message to the SBC, the SBC acknowledges that there is an upper registration route and forwards the request to the softswitch. The softswitch reguires digest authentication and sends a 401 unauthorized back. I would expect now that this message is relayed back to the original client in order to continue with the authentication.
>
>
>
> For some reason, that message never arrives at the client - therefore the client is trying and trying to authenticate.
>
>
>
>
>
>
>
> Here is what I' m seeing in the log file:
>
>
>
> 337066:25:26.471 INF: [CID=0x0e02] <<< REGISTER sip:sip.fakedomain.net SIP/2.0 SRC: 192.168.10.3:37934:UDP enc=0 bytes=576
> 337066:25:26.471 DBG: [CID=0x0e02]
> 337066:25:26.471 DBG: [CID=0x0e02] REGISTER sip:sip.fakedomain.net SIP/2.0
> 337066:25:26.471 DBG: [CID=0x0e02] From: "SoftClient01" <sip:862...@si...>;tag=6613195e
> 337066:25:26.471 DBG: [CID=0x0e02] To: "SoftClient01" <sip:862...@si...>
> 337066:25:26.471 DBG: [CID=0x0e02] Via: SIP/2.0/UDP 192.168.10.3:37934;branch=z9hG4bK-d87543-30153228e21d0017-1--d87543-
> 337066:25:26.471 DBG: [CID=0x0e02] CSeq: 1 REGISTER
> 337066:25:26.471 DBG: [CID=0x0e02] Call-ID: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.471 DBG: [CID=0x0e02] Contact: <sip:8621430679@192.168.10.3:37934;rinstance=6e999ef109459e0f>
> 337066:25:26.471 DBG: [CID=0x0e02] User-Agent: X-Lite release 1011s stamp 41150
> 337066:25:26.471 DBG: [CID=0x0e02] Expires: 3600
> 337066:25:26.471 DBG: [CID=0x0e02] Max-Forwards: 70
> 337066:25:26.471 DBG: [CID=0x0e02] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
> 337066:25:26.471 DBG: [CID=0x0e02] Content-Length: 0
> 337066:25:26.471 DBG: [CID=0x0e02]
> 337066:25:26.471 DBG: [CID=0x0e02]
> 337066:25:26.473 DBG: [CID=0x0e02] Finding transaction for REGISTER sip:sip.fakedomain.net SIP/2.0
> 337066:25:26.473 DBG: [CID=0x0e02] Setting Transaction ID to OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK-d87543-30153228e21d0017-1--d87543-|REGISTER
> 337066:25:26.474 DBG: [CID=0x0e02]
> 337066:25:26.474 DBG: [CID=0x0e02] *** CREATING TRANSACTION (NIST) ***
> 337066:25:26.474 DBG: [CID=0x0e02] Message: REGISTER sip:sip.fakedomain.net SIP/2.0
> 337066:25:26.474 DBG: [CID=0x0e02] Call-Id: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.474 DBG: [CID=0x0e02]
> 337066:25:26.475 DTL: [CID=0x0e02] NIST(2258349004) *** CREATED *** - NIST|OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK-d87543-30153228e21d0017-1--d87543-|REGISTER
> 337066:25:26.477 DTL: [CID=0x0e02] NIST(2258349004) Event(SIPMessage) - REGISTER sip:sip.fakedomain.net SIP/2.0
> 337066:25:26.477 DBG: [CID=0x0e02] TRANSACTION: (NIST) REGISTER sip:sip.fakedomain.net SIP/2.0 State: 0
> 337066:25:26.478 DTL: [CID=0x0e02] NIST(2258349004) StateIdle->StateTrying
> 337066:25:26.478 DBG: [CID=0x0e02] Event: SIPStack::Enqueue(REGISTER sip:sip.fakedomain.net SIP/2.0)
> 337066:25:26.480 DBG: [CID=0x0e02] Event: B2BUserAgent::ProcessEvent( REGISTER sip:sip.fakedomain.net SIP/2.0 )
> 337066:25:26.484 DBG: [CID=0x0e02] Event: Setting UA Core [Proxy] to handle event REGISTER
> 337066:25:26.484 DTL: [CID=0x0e02] Event: ---> Inbound - REGISTER sip:sip.fakedomain.net SIP/2.0
> 337066:25:26.485 DBG: [CID=0x0e02] Session CREATED
> 337066:25:26.486 INF: [CID=0x0e02] *** CREATED *** PROXY Session OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.487 DBG: [CID=0x0e02] *** MESSAGE ARRIVAL *** for SIP Session OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.493 DTL: [CID=0x0e02] Found NIST|OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK-d87543-30153228e21d0017-1--d87543-|REGISTER for SIP/2.0 100 Trying
> 337066:25:26.494 DTL: [CID=0x0e02] NIST(2258349004) Event(SIPMessage) - SIP/2.0 100 Trying
> 337066:25:26.494 DBG: [CID=0x0e02] TRANSACTION: (NIST) SIP/2.0 100 Trying State: 1
> 337066:25:26.495 DTL: [CID=0x0e02] NIST(2258349004) StateTrying->StateProceeding
> 337066:25:26.499 INF: [CID=0x0e02] >>> SIP/2.0 100 Trying DST: 192.168.10.3:37934:UDP SRC: 85.xxx.x.200:5060 enc=0 bytes=388
> 337066:25:26.500 DBG: [CID=0x0e02]
> 337066:25:26.500 DBG: [CID=0x0e02] SIP/2.0 100 Trying
> 337066:25:26.500 DBG: [CID=0x0e02] From: "SoftClient01" <sip:862...@si...>;tag=6613195e
> 337066:25:26.500 DBG: [CID=0x0e02] To: "SoftClient01" <sip:862...@si...>
> 337066:25:26.500 DBG: [CID=0x0e02] Via: SIP/2.0/UDP 192.168.10.3:37934;iid=16143;branch=z9hG4bK-d87543-30153228e21d0017-1--d87543-;rport=37934;received=192.168.10.3
> 337066:25:26.500 DBG: [CID=0x0e02] CSeq: 1 REGISTER
> 337066:25:26.500 DBG: [CID=0x0e02] Call-ID: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.500 DBG: [CID=0x0e02] Server: OpenSBC v1.1.5-6
> 337066:25:26.500 DBG: [CID=0x0e02] Content-Length: 0
> 337066:25:26.500 DBG: [CID=0x0e02]
> 337066:25:26.500 DBG: [CID=0x0e02]
> 337066:25:26.504 INF: [CID=0x0e02] Routing REGISTER for URI sip:862...@si...
> 337066:25:26.505 PWL: [CID=0x0000] -->> From: sip:862...@si... Target: REGISTER sip:862...@so...;domain=softswitch.mydomain.net
> 337066:25:26.507 INF: [CID=0x0e02] *** UPPER REGISTRATION ENABLE *** for sip:862...@si...
> 337066:25:26.511 DBG: [CID=0x06cb] CREATED via=85.xxx.x.200:5060 for target=85.xxx.x.85 protocol=UDP
> 337066:25:26.513 DBG: [CID=0x0e02] Proxying request REGISTER sip:softswitch.mydomain.net SIP/2.0
> 337066:25:26.516 DBG: [CID=0x0e02] Finding transaction for REGISTER sip:softswitch.mydomain.net SIP/2.0
> 337066:25:26.516 DBG: [CID=0x0e02] Setting Transaction ID to OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220|REGISTER
> 337066:25:26.517 DBG: [CID=0x0e02]
> 337066:25:26.517 DBG: [CID=0x0e02] *** CREATING TRANSACTION (NICT) ***
> 337066:25:26.517 DBG: [CID=0x0e02] Message: REGISTER sip:softswitch.mydomain.net SIP/2.0
> 337066:25:26.517 DBG: [CID=0x0e02] Call-Id: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.517 DBG: [CID=0x0e02]
> 337066:25:26.518 DTL: [CID=0x0e02] NICT(2258349005) *** CREATED *** - NICT|OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220|REGISTER
> 337066:25:26.520 DTL: [CID=0x0e02] NICT(2258349005) Event(SIPMessage) - REGISTER sip:softswitch.mydomain.net SIP/2.0
> 337066:25:26.521 DBG: [CID=0x0e02] TRANSACTION: (NICT) REGISTER sip:softswitch.mydomain.net SIP/2.0 State: 0
> 337066:25:26.521 DTL: [CID=0x0e02] NICT(2258349005) StateIdle->StateTrying(REGISTER sip:softswitch.mydomain.net SIP/2.0)
> 337066:25:26.521 DBG: [CID=0x0e02] NICT(2258349005) Timer E( 500 ms ) STARTED
> 337066:25:26.521 DBG: [CID=0x0e02] NICT(2258349005) Timer F( 10000 ms ) STARTED
> 337066:25:26.528 INF: [CID=0x0e02] >>> REGISTER sip:softswitch.mydomain.net SIP/2.0 DST: 85.xxx.x.85:5060:UDP SRC: 85.xxx.x.200:5060 enc=0 bytes=770
> 337066:25:26.529 DBG: [CID=0x0e02]
> 337066:25:26.529 DBG: [CID=0x0e02] REGISTER sip:softswitch.mydomain.net SIP/2.0
> 337066:25:26.529 DBG: [CID=0x0e02] From: "SoftClient01" <sip:862...@so...>;tag=6613195e
> 337066:25:26.529 DBG: [CID=0x0e02] To: "SoftClient01" <sip:862...@si...>
> 337066:25:26.529 DBG: [CID=0x0e02] Via: SIP/2.0/UDP 85.xxx.x.200:5060;iid=16143;branch=z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220;uas-addr=85.xxx.x.85;rport
> 337066:25:26.529 DBG: [CID=0x0e02] Via: SIP/2.0/UDP 192.168.10.3:37934;branch=z9hG4bK-d87543-30153228e21d0017-1--d87543-;rport=37934;received=192.168.10.3
> 337066:25:26.529 DBG: [CID=0x0e02] CSeq: 1 REGISTER
> 337066:25:26.529 DBG: [CID=0x0e02] Call-ID: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.529 DBG: [CID=0x0e02] Contact: <sip:862...@85....x.200:5062;rinstance=6e999ef109459e0f>
> 337066:25:26.529 DBG: [CID=0x0e02] User-Agent: OpenSBC v1.1.5-6
> 337066:25:26.529 DBG: [CID=0x0e02] Expires: 3600
> 337066:25:26.529 DBG: [CID=0x0e02] Max-Forwards: 69
> 337066:25:26.529 DBG: [CID=0x0e02] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
> 337066:25:26.529 DBG: [CID=0x0e02] Content-Length: 0
> 337066:25:26.529 DBG: [CID=0x0e02]
> 337066:25:26.529 DBG: [CID=0x0e02]
> 337066:25:26.544 INF: [CID=0x0e02] <<< SIP/2.0 401 Unauthorized SRC: 85.xxx.x.85:5060:UDP enc=0 bytes=681
> 337066:25:26.545 DBG: [CID=0x0e02]
> 337066:25:26.545 DBG: [CID=0x0e02] SIP/2.0 401 Unauthorized
> 337066:25:26.545 DBG: [CID=0x0e02] From: "SoftClient01" <sip:862...@so...>;tag=6613195e
> 337066:25:26.545 DBG: [CID=0x0e02] To: "SoftClient01" <sip:862...@si...>;tag=1_1146_t930_7352
> 337066:25:26.545 DBG: [CID=0x0e02] Via: SIP/2.0/UDP 85.xxx.x.200:5060;iid=16143;branch=z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220;uas-addr=85.xxx.x.85;rport=5060;received=85.xxx.x.200
> 337066:25:26.545 DBG: [CID=0x0e02] Via: SIP/2.0/UDP 192.168.10.3:37934;branch=z9hG4bK-d87543-30153228e21d0017-1--d87543-;rport=37934;received=192.168.10.3
> 337066:25:26.545 DBG: [CID=0x0e02] CSeq: 1 REGISTER
> 337066:25:26.545 DBG: [CID=0x0e02] Call-ID: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:26.545 DBG: [CID=0x0e02] WWW-Authenticate: Digest realm="ccsip", nonce="455432f8519b24380e57d40f5f2cca7f", algorithm=MD5, qop="auth"
> 337066:25:26.545 DBG: [CID=0x0e02] Content-Length: 0
> 337066:25:26.545 DBG: [CID=0x0e02]
> 337066:25:26.545 DBG: [CID=0x0e02]
> 337066:25:26.546 DBG: [CID=0x0e02] Finding transaction for SIP/2.0 401 Unauthorized
> 337066:25:26.546 DBG: [CID=0x0e02] Setting Transaction ID to OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220|REGISTER
> 337066:25:26.547 DTL: [CID=0x0e02] Found NICT|OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220|REGISTER for SIP/2.0 401 Unauthorized
> 337066:25:26.548 DTL: [CID=0x0e02] NICT(2258349005) Event(SIPMessage) - SIP/2.0 401 Unauthorized
> 337066:25:26.548 DBG: [CID=0x0e02] TRANSACTION: (NICT) SIP/2.0 401 Unauthorized State: 1
> 337066:25:26.548 DTL: [CID=0x0e02] NICT(2258349005) StateTrying->StateCompleted
> 337066:25:26.548 DBG: [CID=0x0e02] NICT(2258349005) Timer E STOPPED
> 337066:25:26.549 DBG: [CID=0x0e02] NICT(2258349005) Timer F STOPPED
> 337066:25:26.549 DBG: [CID=0x0e02] Event: SIPStack::Enqueue(SIP/2.0 401 Unauthorized)
> 337066:25:26.550 DBG: [CID=0x0e02] NICT(2258349005) Timer K( 5000 ms ) STARTED
> 337066:25:26.551 DBG: [CID=0x0e02] Event: B2BUserAgent::ProcessEvent( SIP/2.0 401 Unauthorized )
> 337066:25:26.553 DBG: [CID=0x0e02] Event: Setting UA Core [Proxy] to handle event REGISTER
> 337066:25:26.553 DTL: [CID=0x0e02] Event: ---> Inbound - SIP/2.0 401 Unauthorized
> 337066:25:26.554 DBG: [CID=0x0e02] *** MESSAGE ARRIVAL *** for SIP Session OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:32.700 DBG: [CID=0x0e02] NICT(2258349005) Timer K( 5000 ms ) EXPIRED
> 337066:25:32.706 DBG: [CID=0x0e02] Finding transaction for SIP/2.0 401 Unauthorized
> 337066:25:32.707 DBG: [CID=0x0e02] Setting Transaction ID to OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.|z9hG4bK4cba98df6938dd118b1d98e0e14f783f-69bc052885e284aa4b0d2044600ff220|REGISTER
> 337066:25:32.708 DBG: [CID=0x0e02]
> 337066:25:32.708 DBG: [CID=0x0e02] *** TRANSACTION DOES NOT EXIST ***
> 337066:25:32.708 DBG: [CID=0x0e02] Message: SIP/2.0 401 Unauthorized
> 337066:25:32.708 DBG: [CID=0x0e02] Call-Id: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:32.708 DBG: [CID=0x0e02]
> 337066:25:32.709 DTL: [CID=0x06cb] *** QUEUED FOR DELETION *** SIPSession: OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:32.709 DBG: [CID=0x0000] GC: First Stale Object ProxySession
> 337066:25:32.722 INF: [CID=0x0e02] *** DESTROYED *** PROXY Session OWFkMTI4ODljOGQ3NjA1MDM1NzY0ZGViZDUzMjZmMmM.
> 337066:25:32.722 DBG: [CID=0x0e02] PROXY: Session DESTROYED
>
>
>
>
>
>
>
>
>
>
>
>
>
> Has somebody seen such a behavior ? Is my expectation right that the SBC should forward the request and not close the proxy session immediately ?
>
>
>
>
> Many thanks in advance.
>
>
>
> Andre
|
