< Previous by Date | Date Index | Next by Date > |
< Previous in Thread | Thread Index |
Scott: That’s right, that’s the log
after we modify the route header for Notify message. It is not the one set up
by resip/dum(not work). We tried to set loadbalancer IP and port as received
and rport in route. I don’t have the log w/o doing any change on hand. Will
need to replace code there to get log, but I am unable to find a window to do
it for a while, guess we will stick to the fix we have and hope 1.7 release
might fix it. I think this is a bug in resip/dum 1.6 release. Wei Li ICP Client Team, Verizon Business From: slgodin@xxxxxxxxx
[mailto:slgodin@xxxxxxxxx] On Behalf Of Scott Godin Is the Subscription server also based on resip/dum? If
so, are you saying that the resip/dum Subscription server did not properly set
the Route headers on the Notify request (using the Record-Route on the
Subscribe), or that when the message was passed back through repro, that it did
not correctly find the connection/flow even though it was using a flow token in
the route? The logs you posted show the Via header being copied to the
Route header, and does not show the Route headers being formed from the
Subscribe Record-Routes. Scott On Mon, Sep 27, 2010 at 12:52 PM, Li, Wei (Wei) <wei.li@verizon.com>
wrote: Scott: Yes, we enabled
flow token, and code is based on 1.6 release. Byron said the
base64 string in user part of subscribe record-route recorded all the routes,
to set routes for notify, it will copy those record-routes in reverse order and
put into route headers. This should be handled automatically in repro stack,
but testing shows it doesn’t work, it still uses 113.128.245.176:4078 to
locate a FD. So our solution is to manually set up Notify routes from Vias of
subscribe request, if via has rport and received, use them to replace
route’s host and port. This actually makes it work. Wei Li ICP
Client Team, Verizon Business From: slgodin@xxxxxxxxx [mailto:slgodin@xxxxxxxxx] On
Behalf Of Scott Godin 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:
Wei Li ICP
Client Team, Verizon Business From: Li,
Wei (Wei) 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
|