[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