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

[reSIProcate] Help on SUBSCRIBE behaviour in TCP


Hi,
 
I am using SUBSCRIBE-NOTIFY mechanism in my module.
I am using Resiprocate Stack.
 
I am writing an application as a Subscriber and initiating a Subscription.
I have derived from ClientSubscriptionHandler and defined the callbacks.
 
Scenario:
When I am running Subscriber in TCP mode an when Notifier is not running:
 
Subscriber tries to open a socket for TCP connection and fails as Notifier is not running.
But here 503 Service Unavailable response is received and an exception is caught telling:  "Subscription-State Header is missing in the Response.
I have attached the log file:TCP_log.txt, please have a look at it.
 
Subscription State Header is not mandatory in the Error Responses.
The match is done based on CallId, From tag and CSeq No.  according to RFC3265 
Why is it throwing the Exception?
--------------
 
My purpose is: The Subscriber should keep on trying to send SUBSCRIBE till the Notifier comes up or starts listening.
 
Should I run a new timer in my application or can I reuse from the stack.
 
Can someone explain the purpose of onRequestRetry() callback?
How should I proceed?
 
Please reply.
 
Regards,
Parimala
 
DEBUG | 20060614-151214.204 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
BaseCreator.cxx:90 | BaseCreator::makeInitialRequest: SUBSCRIBE 
sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp SIP/2.0
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/ ;branch=z9hG4bK-d87543-a9cd84477f7c5a5b-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Contact: <sip:test>
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, SUBSCRIBE
Content-Length: 0


DEBUG | 20060614-151214.205 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogSet.cxx:51 |  ************* Created DialogSet(UAC)  -- 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b*************
DEBUG | 20060614-151214.206 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogUsageManager.cxx:382 | ************* Adding DialogSet ***************
DEBUG | 20060614-151214.206 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogUsageManager.cxx:383 | Before: []
DEBUG | 20060614-151214.206 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogUsageManager.cxx:385 | After: 
[fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b -> 0x8256c08]
DEBUG | 20060614-151214.206 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogUsageManager.cxx:1493 | Looking for dialogSet: 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b in map:
DEBUG | 20060614-151214.206 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogUsageManager.cxx:1494 | [fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b 
-> 0x8256c08]
DEBUG | 20060614-151214.207 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogUsageManager.cxx:607 | SEND: SUBSCRIBE 
sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp SIP/2.0
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/ ;branch=z9hG4bK-d87543-a9cd84477f7c5a5b-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Contact: <sip:test>
Expires: 9900
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, SUBSCRIBE
User-Agent: mrfc/1.0
Event: mcast_vod_subscription
Content-Length: 0


DEBUG | 20060614-151214.207 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 229391 | 
DialogId.cxx:50 | DialogId::DialogId: 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b-
DEBUG | 20060614-151214.207 | ccsc2.wipro.com |  | RESIP | 25735 | 229391 | 
SipStack.cxx:269 | SEND: SipReq:  SUBSCRIBE multicast_vod@xxxxxxxxxxxxx:5199 
tid=a9a92e3eb5c80667 cseq=SUBSCRIBE contact=test / 1 from(tu)

DEBUG | 20060614-151214.222 | ccsc2.wipro.com |  | RESIP:TRANSACTION | 25735 | 
16386 | TimerQueue.cxx:85 | Adding timer: Timer F tid=a9a92e3eb5c80667 ms=32000
DEBUG | 20060614-151214.223 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TransportSelector.cxx:243 | Looking up dns entries for 
sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp
DEBUG | 20060614-151214.223 | ccsc2.wipro.com |  | RESIP:DNS | 25735 | 16386 | 
DnsResult.cxx:136 | DnsResult::lookup 
sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp
DEBUG | 20060614-151214.223 | ccsc2.wipro.com |  | RESIP:DNS | 25735 | 16386 | 
DnsResult.cxx:152 | Found immediate result: [ V4 10.10.200.216:5199 TCP 
connectionId=0 ]
DEBUG | 20060614-151214.223 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | InternalTransport.cxx:87 | Creating fd=12 V4/UDP
DEBUG | 20060614-151214.224 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TransportSelector.cxx:514 | Looked up source for destination: [ V4 
10.10.200.216:5199 TCP connectionId=0 ] -> [ V4 10.10.200.216:0 TCP 
connectionId=0 ] sent-by= sent-port=0
DEBUG | 20060614-151214.224 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TransportSelector.cxx:740 | findTransport([ V4 10.10.200.216:0 TCP 
connectionId=0 ])
DEBUG | 20060614-151214.224 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TransportSelector.cxx:782 | findTransport (any port, any interface) => 
Transport: [ V4 0.0.0.0:5190 TCP connectionId=0 ]
DEBUG | 20060614-151214.224 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TransportSelector.cxx:620 | !sipit! Populated Contact: 
<sip:test@xxxxxxxxxxxxx:5190;transport=TCP>
DEBUG | 20060614-151214.224 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TransportSelector.cxx:658 | Transmitting to [ V4 10.10.200.216:5199 TCP 
received on: Transport: [ V4 0.0.0.0:5190 TCP connectionId=0 ] connectionId=0 ] 
via [ V4 10.10.200.216:0 TCP connectionId=0 ]SUBSCRIBE 
sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp SIP/2.0
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Contact: <sip:test@xxxxxxxxxxxxx:5190;transport=TCP>
Expires: 9900
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, SUBSCRIBE
User-Agent: mrfc/1.0
Event: mcast_vod_subscription
Content-Length: 0


DEBUG | 20060614-151214.225 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | Transport.cxx:160 | Adding message to tx buffer to: [ V4 
10.10.200.216:5199 TCP received on: Transport: [ V4 0.0.0.0:5190 TCP 
connectionId=0 ] connectionId=0 ]
DEBUG | 20060614-151214.225 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TcpBaseTransport.cxx:173 | Processing write for [ V4 10.10.200.216:5199 
TCP received on: Transport: [ V4 0.0.0.0:5190 TCP connectionId=0 ] 
connectionId=0 ]
DEBUG | 20060614-151214.226 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | InternalTransport.cxx:87 | Creating fd=13 V4/TCP
DEBUG | 20060614-151214.226 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TcpBaseTransport.cxx:213 | Opening new connection to [ V4 
10.10.200.216:5199 TCP received on: Transport: [ V4 0.0.0.0:5190 TCP 
connectionId=0 ] connectionId=0 ]
DEBUG | 20060614-151214.226 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | ConnectionBase.cxx:42 | ConnectionBase::ConnectionBase, who: [ V4 
10.10.200.216:5199 TCP received on: Transport: [ V4 0.0.0.0:5190 TCP 
connectionId=0 ] connectionId=0 ] 0x82cda00
DEBUG | 20060614-151214.226 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TcpConnection.cxx:16 | Creating TCP connection [ V4 10.10.200.216:5199 
TCP received on: Transport: [ V4 0.0.0.0:5190 TCP connectionId=0 ] 
connectionId=0 ] on 13
DEBUG | 20060614-151214.227 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | Connection.cxx:64 | Sending 557 bytes
DEBUG | 20060614-151214.227 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TcpConnection.cxx:81 | Writing SUBSCRIBE 
sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp SIP/2.0
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Contact: <sip:test@xxxxxxxxxxxxx:5190;transport=TCP>
Expires: 9900
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, SUBSCRIBE
User-Agent: mrfc/1.0
Event: mcast_vod_subscription
Content-Length: 0


INFO | 20060614-151214.227 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | TcpConnection.cxx:95 | Failed write on 13 Connection refused
INFO | 20060614-151214.227 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | Transport.cxx:142 | Some other error (111): Connection refused
INFO | 20060614-151214.227 | ccsc2.wipro.com |  | RESIP:TRANSPORT | 25735 | 
16386 | Connection.cxx:70 | Write failed on socket: 13, closing connection
INFO | 20060614-151214.228 | ccsc2.wipro.com |  | RESIP:TRANSACTION | 25735 | 
16386 | TransactionState.cxx:1273 | Try sending request to a different dns 
result
INFO | 20060614-151214.228 | ccsc2.wipro.com |  | RESIP:TRANSACTION | 25735 | 
16386 | TransactionState.cxx:1253 | Ran out of dns entries for 10.10.200.216. 
Send 503
DEBUG | 20060614-151214.228 | ccsc2.wipro.com |  | RESIP | 25735 | 16386 | 
Helper.cxx:296 | Helper::makeResponse(SipReq:  SUBSCRIBE 
multicast_vod@xxxxxxxxxxxxx:5199 tid=a9a92e3eb5c80667 cseq=SUBSCRIBE 
contact=test@xxxxxxxxxxxxx:5190 / 1 from(tu) code=503 reason=
DEBUG | 20060614-151214.229 | ccsc2.wipro.com |  | RESIP:TRANSACTION | 25735 | 
16386 | TransactionState.cxx:1535 | Send to TU: TU: DialogUsageManager size=0 
SIP/2.0 503 Service Unavailable
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Warning: 499 ccsc2.wipro.com "No other DNS entries to try"
Content-Length: 0


INFO | 20060614-151214.230 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogUsageManager.cxx:830 | Got: SipResp: 503 tid=a9a92e3eb5c80667 
cseq=SUBSCRIBE / 1 from(wire)
DEBUG | 20060614-151214.230 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogUsageManager.cxx:1380 | DialogUsageManager::processResponse: SIP/2.0 503 
Service Unavailable
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Warning: 499 ccsc2.wipro.com "No other DNS entries to try"
Content-Length: 0


DEBUG | 20060614-151214.280 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogUsageManager.cxx:1493 | Looking for dialogSet: 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b in map:
DEBUG | 20060614-151214.280 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogUsageManager.cxx:1494 | [fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b 
-> 0x8256c08]
DEBUG | 20060614-151214.280 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogUsageManager.cxx:1395 | DialogUsageManager::processResponse: SipResp: 503 
tid=a9a92e3eb5c80667 cseq=SUBSCRIBE / 1 from(wire)
DEBUG | 20060614-151214.280 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogId.cxx:50 | DialogId::DialogId: 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b-4757296a
DEBUG | 20060614-151214.280 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogSet.cxx:665 | findDialog: 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b-4757296a in []
DEBUG | 20060614-151214.281 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogSet.cxx:600 | Creating a new Dialog from msg: SIP/2.0 503 Service 
Unavailable
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Warning: 499 ccsc2.wipro.com "No other DNS entries to try"
Content-Length: 0


DEBUG | 20060614-151214.281 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogId.cxx:50 | DialogId::DialogId: 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b-4757296a
DEBUG | 20060614-151214.281 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:197 | ************** Created Dialog as UAC **************
DEBUG | 20060614-151214.281 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:198 | mRemoteNameAddr: 
<sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
DEBUG | 20060614-151214.282 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:199 | mLocalNameAddr: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
DEBUG | 20060614-151214.282 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:200 | mLocalContact: <sip:>
DEBUG | 20060614-151214.282 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:201 | mRemoteTarget: <sip:>
DEBUG | 20060614-151214.282 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:206 | Dialog::Dialog 
fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t-614f047b-4757296a
DEBUG | 20060614-151214.282 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogSet.cxx:635 | ### Calling CreateAppDialog ### SIP/2.0 503 Service 
Unavailable
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Warning: 499 ccsc2.wipro.com "No other DNS entries to try"
Content-Length: 0


DEBUG | 20060614-151214.283 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:289 | Dialog::dispatch: SipResp: 503 tid=a9a92e3eb5c80667 
cseq=SUBSCRIBE / 1 from(wire)
DEBUG | 20060614-151214.283 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
Dialog.cxx:850 | Dialog::makeRequest: SUBSCRIBE sip: SIP/2.0
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/ ;branch=z9hG4bK-d87543-4dbc991874b6314a-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 2 SUBSCRIBE
Contact: <sip:>
Expires: 9900
Max-Forwards: 70
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, SUBSCRIBE
User-Agent: mrfc/1.0
Event: mcast_vod_subscription
Content-Length: 0


MRFC_DEBUG: DialogHandler 0:: 
ClientSubscriptionHandle-------------onTerminated() received=  SIP/2.0 503 
Service Unavailable
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Warning: 499 ccsc2.wipro.com "No other DNS entries to try"
Content-Length: 0


INFO | 20060614-151214.316 | ccsc2.wipro.com |  | RESIP | 25735 | 32771 | 
SipMessage.cxx:1064 | Missing Header [Subscription-State]
DEBUG | 20060614-151214.316 | ccsc2.wipro.com |  | RESIP | 25735 | 32771 | 
SipMessage.cxx:1065 | SIP/2.0 503 Service Unavailable
To: <sip:multicast_vod@xxxxxxxxxxxxx:5199;transport=tcp>;tag=4757296a
From: <sip:test@xxxxxxxxxxxxxxx>;tag=614f047b
Via: SIP/2.0/TCP 
10.10.200.216:5190;branch=z9hG4bK-d87543-a9a92e3eb5c80667-1--d87543-;rport
Call-ID: fb74db5f84b5f165@Y2NzYzIud2lwcm8uY29t
CSeq: 1 SUBSCRIBE
Warning: 499 ccsc2.wipro.com "No other DNS entries to try"
Content-Length: 0


DEBUG | 20060614-151214.317 | ccsc2.wipro.com |  | RESIP | 25735 | 32771 | 
os/BaseException.cxx:17 | BaseException at SipMessage.cxx:1066 Missing header 
Subscription-State
ERR | 20060614-151214.318 | ccsc2.wipro.com |  | RESIP:DUM | 25735 | 32771 | 
DialogUsageManager.cxx:965 | Illegal message rejected: Missing header 
Subscription-State