reSIProcate

Mailing Lists

Source Code

Google Search:



< Previous by Date Date Index Next by Date >
< Previous in Thread Thread Index Next in Thread >

Re: [reSIProcate-users] repro proxy 1.6 unable to find right fd

Hi Wei,

" I think it could be something wrong on how we set the header of the initial notify(routes),  we did it based on vias from subscribe request. Your help is very appreciated."

Repro stores connection information based on the source or destination IP and port.  The connections between the load balancer and repro are all stored with the 192.76.66.6 address.  However the top route on your NOTIFY is pointing to 113.128.245.176:4078 - therefor repro cannot find an existing connection directly to this IP, and attempts to form a new one.

I think the solution would be to get your Event Package UA to route the NOTIFY requests based on the Record-Route headers from the Subscribe (ie. Copy Record-Route headers from Subscribe to Route headers on the NOTIFY request).  Having flow tokens in the route headers should help repro find the correct connections to route on.

Regards,
Scott

On Wed, Sep 15, 2010 at 3:21 PM, Li, Wei (Wei) <wei.li@verizon.com> wrote:


The repro proxy doesn't find the right FD if I pass a Via with a received parameter, how can I fix this? Please refer the log in attached emails.

 

Wei Li

ICP Client Team, Verizon Business

 

From: Li, Wei (Wei)
Sent: Tuesday, September 07, 2010 5:18 PM
To: resiprocate-users
Subject: resip 1.6 routing issue with TLS in loadbalancing environment, please help

 

I have enabled flow token, also specifically bind the proxy server to IP and ports.

 

But I ran into problem when testing SIPS, we have a loadbalancer before proxy, here is the figure:

 

Client(UA, 113.128.245.176:4078) <->LoadBalancer(192.76.66.5:22361)<->Proxy(113.128.247.39:5060)<->EventPackage(UA, 113.128.245.176:13000)

---------------------------------TLS------------------------------------------------------------------------------------

                                                                                                                                                  -------------------------------------TCP------------------------------------------------

Note: Client and Event Package are on same box, all firewall rules have been set, no problem there.                                                                                                                                                                                                                                      

Registration works fine, subscription seems fine until intianl Notify is unable to be delivered from Proxy, log suggested proxy to look up tuple with client’s  IP address and port , instead of loadbalancer’s IP and port. Thus it couldn’t find the connection and try to create a new connection directly back to client, that fails because it has to go back through loadbalancer.  I think it could be something wrong on how we set the header of the initial notify(routes),  we did it based on vias from subscribe request. Your help is very appreciated.

 

 

Included Subscribe request, Initial Notify message and proxy error log.

 

Subscribe Request:

DEBUG | 20100907-172038.510 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | TcpConnection.cxx:83 | Writing SUBSCRIBE sip:profile@xxxxxxxxxxxxxxx:13000;rinstance=b6fb275a12611691;transport=TCP SIP/2.0

 

Via: SIP/2.0/TCP 113.128.247.39:5060;branch=z9hG4bK-d8754z-376ee92061489e40-1---d8754z-;rport

 

Via: SIP/2.0/TLS 113.128.245.176:4078;branch=z9hG4bK-d8754z-062fb435fa72a41e-1---d8754z-;rport=22361;received=192.76.66.5

 

Max-Forwards: 69

 

Record-Route: <sip:AAAAAAACyDJxgPWw@xxxxxxxxxxxxxx:5060;transport=TCP;lr>

 

Record-Route: <sip:7AMAAAABWVfATEIF@xxxxxxxxxxxxxx;lr;lp>

 

Identity: gY0RPzLO4j8WK8OTBwkEWu3/SOXaV3bwNsjWxr2EN41Ybqlxmb+R47QKncCBaMHbDtUbiIGzg6pPYzJO0QCwCGpB9gXqhk3rFeTInpZ0+W2toUOrywjS1rHkKXigfCrdLrEopaaxurDsSLlHPAQmXnf97RjWc8euiZoguSJOgEY=

 

Identity-Info: <http://.....:5080/cert?domain=ucc.vzb.com>

 

Contact: <sip:icp9116498@xxxxxxxxxxxxxxx:4078;transport=TLS>

 

To: <sip:profile@xxxxxxxxxxxxxxx>

 

From: <sip:icp9116498@xxxxxxxxxxx>;tag=7644ba66

 

Call-ID: OWE5MmEzZWE5MzI3Mjc3YmE2NWM5YWE3YzIxNDNmYTM.

 

CSeq: 2 SUBSCRIBE

 

Expires: 900

 

Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, UPDATE, MESSAGE, SUBSCRIBE, PUBLISH, NOTIFY

 

Date: Tue, 07 Sep 2010 21:20:38 GMT

 

Proxy-Authorization: Digest username="icp9116498",realm="ucc.vzb.com",nonce="12928368038:56a3e645f35514635a213d9b9c852a2a",uri="sip:profile@xxxxxxxxxxxxxxx",response="9516fe58de2d21ed0f4330da311b45bb",cnonce="1dae3cc1627b08ad21636f17c4e24e69",nc=00000001,qop=auth-int,algorithm=MD5

 

Event: profile

 

ApplicationId: ProxyLBTestTool

 

ApplicationVersion: 2.0

 

Content-Length: 0

 

Initial Notify request:

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | Proxy.cxx:89 | Got: NOTIFY sip:icp9116498@xxxxxxxxxxxxxx:5060;branch=z9hG4bK-d8754z-376ee92061489e40-1---d8754z-;rport=1328;transport=TCP SIP/2.0

 

Via: SIP/2.0/TCP 113.128.245.176:13000;branch=z9hG4bK-d8754z-55695b3f4601b974-1---d8754z-;rport=4037

 

Max-Forwards: 70

 

Route: <sip:icp9116498@xxxxxxxxxxxxxxx:4078;branch=z9hG4bK-d8754z-062fb435fa72a41e-1---d8754z-;rport=22361;received=192.76.66.5;transport=TLS>

 

Route: <sip:icp9116498@xxxxxxxxxxxxxxx:4078;transport=TLS>

 

Contact: <sip:profile@xxxxxxxxxxxxxxx:13000;rinstance=b6fb275a12611691;transport=TCP>

 

To: <sip:icp9116498@xxxxxxxxxxx>;tag=7644ba66

 

From: <sip:profile@xxxxxxxxxxxxxxx>;tag=0d21807f

 

Call-ID: OWE5MmEzZWE5MzI3Mjc3YmE2NWM5YWE3YzIxNDNmYTM.

 

CSeq: 2 NOTIFY

 

Content-Type: application/xml

 

Subscription-State: active

 

Event: profile

 

Content-Length: 1148

 

<content>……………………………….

 

 

Proxy error:

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | ResponseContext.cxx:626 | Set tuple dest: [ V4 0.0.0.0:0 UNKNOWN_TRANSPORT target domain=unspecified mFlowKey=0 ]

INFO | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | RequestContext.cxx:621 | Updating timer C.

INFO | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | Proxy.cxx:458 | Posting timer C

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 2956 | TimerQueue.cxx:105 | Adding application timer: TimerCMessage(55695b3f4601b974)

INFO | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | Proxy.cxx:444 | add client transaction tid=32619727ef6b597a 00BE4F80

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | RESIP | 2956 | SipStack.cxx:319 | SEND: SipReq:  NOTIFY icp9116498@xxxxxxxxxxxxxxx:4078 tid=32619727ef6b597a cseq=NOTIFY contact=profile@xxxxxxxxxxxxxxx:13000 / 2 from(wire)

INFO | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | ResponseContext.cxx:279 | Creating new client transaction 32619727ef6b597a -> sip:icp9116498@xxxxxxxxxxxxxx:5060;branch=z9hG4bK-d8754z-376ee92061489e40-1---d8754z-;rport=1328;transport=TCP

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | ProcessorChain.cxx:80 | Monkey aborted all chains: SimpleTargetHandler baboon

 

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | ProcessorChain.cxx:80 | Monkey aborted all chains: Monkey Chain![00BB44E8]

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | Proxy.cxx:89 | Got: ServerTransactionTerminated 062fb435fa72a41e

INFO | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | RequestContext.cxx:70 | RequestContext::process(TransactionTerminated) 062fb435fa72a41e : RequestContext:  identity=icp9116498 count=1 final=1 orig requri=SipReq:  SUBSCRIBE profile@xxxxxxxxxxxxxxxxxxxxxxxxxxx tid=062fb435fa72a41e cseq=SUBSCRIBE contact=icp9116498@xxxxxxxxxxxxxxx:4078 / 2 from(wire) tlsd=ucc.vzb.com

DEBUG | 20100907-172038.557 | Vz.Nexus.Proxy.R3.1.exe | REPRO:APP | 2956 | RequestContext.cxx:53 | RequestContext::~RequestContext() 00BC5378

STACK | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 5260 | TransactionState.cxx:389 | No matching transaction for SipReq:  NOTIFY icp9116498@xxxxxxxxxxxxxxx:4078 tid=32619727ef6b597a cseq=NOTIFY contact=profile@xxxxxxxxxxxxxxx:13000 / 2 from(tu)

STACK | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 5260 | TransactionState.cxx:56 | Creating new TransactionState: tid=32619727ef6b597a [ ClientNonInvite/Trying reliable target=[ V4 0.0.0.0:0 UNKNOWN_TRANSPORT target domain=unspecified mFlowKey=0 ]]

STACK | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 5260 | TransactionState.cxx:661 | TransactionState::processClientNonInvite: SipReq:  NOTIFY icp9116498@xxxxxxxxxxxxxxx:4078 tid=32619727ef6b597a cseq=NOTIFY contact=profile@xxxxxxxxxxxxxxx:13000 / 2 from(tu)

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 5260 | TimerQueue.cxx:85 | Adding timer: Timer F tid=32619727ef6b597a ms=32000

STACK | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 5260 | TransactionState.cxx:2038 | sendToWire with no dns result: tid=32619727ef6b597a [ ClientNonInvite/Trying reliable target=[ V4 0.0.0.0:0 UNKNOWN_TRANSPORT target domain=unspecified mFlowKey=0 ]]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:DNS | 5260 | DnsResult.cxx:207 | DnsResult::lookup sip:icp9116498@xxxxxxxxxxxxxxx:4078;branch=z9hG4bK-d8754z-062fb435fa72a41e-1---d8754z-;rport=22361;received=192.76.66.5;transport=TLS

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:DNS | 5260 | DnsResult.cxx:249 | Found immediate result: [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

STACK | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSACTION | 5260 | TransactionState.cxx:1865 | tid=32619727ef6b597a [ ClientNonInvite/Trying reliable target=[ V4 0.0.0.0:0 UNKNOWN_TRANSPORT target domain=unspecified mFlowKey=0 ]] got DNS result: 113.128.245.176 --> [[ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]]

STACK | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:DNS | 5260 | DnsResult.cxx:187 | Returning next dns entry: [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:70 | ** SEARCHING FOR TUPLE, [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:74 | ** ITEM, [ V4 192.76.66.5:22361 TLS target domain=unspecified mFlowKey=1004 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:74 | ** ITEM, [ V4 192.76.66.6:35888 TLS target domain=unspecified mFlowKey=1172 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:74 | ** ITEM, [ V4 192.76.66.6:17904 TLS target domain=unspecified mFlowKey=1192 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:85 | Could not find a connection for [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | TransportSelector.cxx:1245 | Searching for TLS transport for domain='' have 1

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | TransportSelector.cxx:1254 | Found a default transport.

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | TransportSelector.cxx:945 | Transmitting to [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ] tlsDomain= via [ V4 113.128.247.39:5061 TLS target domain=unspecified mFlowKey=0 ]

 

NOTIFY sip:icp9116498@xxxxxxxxxxxxxxx:4078;branch=z9hG4bK-d8754z-062fb435fa72a41e-1---d8754z-;rport=22361;received=192.76.66.5;transport=TLS SIP/2.0

 

Via: SIP/2.0/TLS 113.128.247.39:5061;branch=z9hG4bK-d8754z-32619727ef6b597a-1---d8754z-;rport

 

Via: SIP/2.0/TCP 113.128.245.176:13000;branch=z9hG4bK-d8754z-55695b3f4601b974-1---d8754z-;rport=4037

 

Max-Forwards: 69

 

Route: <sip:icp9116498@xxxxxxxxxxxxxxx:4078;transport=TLS>

 

Route: <sip:icp9116498@xxxxxxxxxxxxxx:5060;branch=z9hG4bK-d8754z-376ee92061489e40-1---d8754z-;rport=1328;transport=TCP>

 

Contact: <sip:profile@xxxxxxxxxxxxxxx:13000;rinstance=b6fb275a12611691;transport=TCP>

 

To: <sip:icp9116498@xxxxxxxxxxx>;tag=7644ba66

 

From: <sip:profile@xxxxxxxxxxxxxxx>;tag=0d21807f

 

Call-ID: OWE5MmEzZWE5MzI3Mjc3YmE2NWM5YWE3YzIxNDNmYTM.

 

CSeq: 2 NOTIFY

 

Content-Type: application/xml

 

Subscription-State: active

 

Event: profile

 

Content-Length: 1148

 

<content>………………………..

 

sigcomp id=

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | Transport.cxx:213 | Adding message to tx buffer to: [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | TcpBaseTransport.cxx:141 | Processing write for [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:70 | ** SEARCHING FOR TUPLE, [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:74 | ** ITEM, [ V4 192.76.66.5:22361 TLS target domain=unspecified mFlowKey=1004 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:74 | ** ITEM, [ V4 192.76.66.6:35888 TLS target domain=unspecified mFlowKey=1172 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:74 | ** ITEM, [ V4 192.76.66.6:17904 TLS target domain=unspecified mFlowKey=1192 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | ConnectionManager.cxx:85 | Could not find a connection for [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | InternalTransport.cxx:86 | Creating fd=1376 V4/TCP

DEBUG | 20100907-172038.588 | Vz.Nexus.Proxy.R3.1.exe | RESIP:TRANSPORT | 5260 | TcpBaseTransport.cxx:177 | Opening new connection to [ V4 113.128.245.176:4078 TLS target domain=113.128.245.176 mFlowKey=0 ]

DEBUG |

 

It should use fd 1004, instead of creating a new one at 1376

 

 

Wei Li

ICP Client Team, Verizon Business

 


_______________________________________________
resiprocate-users mailing list
resiprocate-users@xxxxxxxxxxxxxxx
List Archive: http://list.resiprocate.org/archive/resiprocate-users/