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

Re: [recon-devel] Some problems occur after session is replaced.


Hi,
 
I am trying to clear up the 2nd problem - Alice and Carol are silent after redirectToParticipant.
 
I had extracted lines including keyword NotificationDispatcher from logs.
 
I think that this log shows the following.
1. Alice does not start stream of RtpDispatcher to receive from Carol.
2. Carol does not start stream of Encode to send to Alice.
 
 
////////// Alice //////////
6 lines matching "NotificationDispatcher" in buffer Alice0128.log.
    829: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-1, connectionId=1, state=STREAM_START, ssrc=1264716018, address=0, port=-1
    837: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-1-RtpDispatcher, connectionId=1, state=STREAM_START, ssrc=1265347042, address=BOBBBBBBB, port=41000
   2306: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-1, connectionId=1, state=STREAM_STOP, ssrc=1264716018, address=0, port=-1
   2381: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-1-RtpDispatcher, connectionId=1, state=STREAM_STOP, ssrc=1265347042, address=BOBBBBBBB, port=41000
   3306: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-2, connectionId=2, state=STREAM_START, ssrc=1265398961, address=0, port=-1
   3691: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-2, connectionId=2, state=STREAM_STOP, ssrc=1265398961, address=0, port=-1
 
////////// Bob //////////
7 lines matching "NotificationDispatcher" in buffer Bob0128.log.
    796: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-1, connectionId=1, state=STREAM_START, ssrc=1265347042, address=0, port=-1
    889: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-1-RtpDispatcher, connectionId=1, state=STREAM_START, ssrc=1264716018, address=ALICEAAAA, port=31000
   2158: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-1, connectionId=1, state=STREAM_STOP, ssrc=1265347042, address=0, port=-1
   2435: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-1-RtpDispatcher, connectionId=1, state=STREAM_STOP, ssrc=1264716018, address=ALICEAAAA, port=31000
   3017: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-2-RtpDispatcher, connectionId=2, state=STREAM_START, ssrc=1264951842, address=CAROLCCCC, port=51000
   3055: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-2, connectionId=2, state=STREAM_START, ssrc=1264798314, address=0, port=-1
   4559: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-2, connectionId=2, state=STREAM_STOP, ssrc=1264798314, address=0, port=-1
 
////////// Carol //////////
4 lines matching "NotificationDispatcher" in buffer Carol0128.log.
    823: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-1, connectionId=1, state=STREAM_START, ssrc=1264951842, address=0, port=-1
    825: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-1-RtpDispatcher, connectionId=1, state=STREAM_START, ssrc=1264798314, address=BOBBBBBBB, port=41002
   2465: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=Encode-1, connectionId=1, state=STREAM_STOP, ssrc=1264951842, address=0, port=-1
   2543: ConversationManager.cxx:714   NotificationDispatcher: received MI_NOTF_RX_STREAM_ACTIVITY, sourceId=InRtp-2-RtpDispatcher, connectionId=2, state=STREAM_START, ssrc=1265398961, address=ALICEAAAA, port=31002
 
Why does it become like this?
Where should I see the log of?
 
Regards,

2010/1/28 Yamato Kira <coordinator.kira@xxxxxxxxx>
Hello,

I appreciate your prompt response.

> 5.  I'm assuming A, B and C are all using recon - is this correct?

Yes.

> 3.  Are you using testUA to produce this scenario?  If so - can you
> please send over the series of commands you are using.
> 4.  Can you please provide a wireshark trace of this - it will help to
> be able to see the contents of the SDP bodies.

I am not using pure original testUA in this scenario.
However, I will describe my opeartions with testUA command.

Today I could not get enough environment for packet capture.
Wireshark instead of, could you see the attached chart?
SIP messages in the chart were created from the DUM DEBUG logs.

> 1.  Are you using a LocalParticipant in the original conversation
> between A and B?  In the 2nd call between B and C?
> 2.  After the call from B to C is placed - what is your conversation
> setup?  Do you have both A and C in the same conversation?  or are the
> two parties in separate Conversations?  If separate - which
> conversation has the Local Participant, if any?
Could you see the chart attached?

Following texts are same as operations written in the chart.

//////////////////////////////////////////////////////////////////
// operations on Alice
//////////////////////////////////////////////////////////////////

echocancel 1
autogain 1
noisereduction 1
createlocal
---partHandle=1 is created.---

createconv
---convHandle=1 is created.---

createconv
---convHandle=2 is created.---

addpart 2 1
volume 75
gain 75
createremote 2 <sip:Bob@repro>
---partHandle=2 is created.---

addpart 2 2

SEND: INVITE sip:Bob@repro SIP/2.0

=== onParticipantAlerting: handle=2 msg=SipResp: 180
tid=8d66ff5e416bb227 cseq=INVITE contact=Bob@xxxxxxxxxxxxxxx:45060 / 1
from(wire) ===

createmedia 1 tone:ringback;local-only
---partHandle=3 is created.---

addpart 1 1

=== onParticipantConnected: handle=2 msg=SipResp: 200
tid=8d66ff5e416bb227 cseq=INVITE contact=Bob@xxxxxxxxxxxxxxx:45060 / 1
from(wire) ===

destroypart 3
removepart 1 1

=== onParticipantDestroyed: handle=3 ===

SEND: SIP/2.0 200 OK

SEND: SIP/2.0 202 Accepted

SEND: NOTIFY sip:Bob@xxxxxxxxxxxxxxx:45060;rinstance=822ef86bd71f5007 SIP/2.0

SEND: INVITE sip:Carol@repro SIP/2.0

SEND: NOTIFY sip:Bob@xxxxxxxxxxxxxxx:45060;rinstance=822ef86bd71f5007 SIP/2.0

SEND: INVITE sip:Carol@xxxxxxxxxxxxxxx:55060;rinstance=dec1ffe9b0904ed5 SIP/2.0

=== onParticipantConnected: handle=2 msg=SipResp: 200
tid=2d2a813cc86a3c7d cseq=INVITE contact=Carol@xxxxxxxxxxxxxxx:55060 /
1 from(wire) ===

SEND: SIP/2.0 491 Request Pending

SEND: SIP/2.0 200 OK

SEND: SIP/2.0 200 OK

//////////////////////////////////////////////////////////////////
// operations on Bob
//////////////////////////////////////////////////////////////////

echocancel 1
autogain 1
noisereduction 1
createlocal
---partHandle=1 is created.---

createconv
---convHandle=1 is created.---

=== onIncomingParticipant: handle=2auto=0 msg=SipReq:  INVITE
Bob@xxxxxxxxxxxxxxx:45060 tid=d570345093bc6b62 cseq=INVITE
contact=Alice@xxxxxxxxxxxxxxx:35060 / 1 from(wire) ===

createconv
---convHandle=2 is created.---

addpart 2 1
volume 75
gain 75
addpart 2 2
alert 2 noearly
createmedia 1 tone:ring;local-only
---partHandle=3 is created.---

addpart 1 1

SEND: SIP/2.0 180 Ringing

answer 2
addpart 2 1
volume 75
gain 75
destroypart 3
removepart 1 1

SEND: SIP/2.0 200 OK

=== onParticipantDestroyed: handle=3 ===

removepart 2 1
createmedia 1 tone:dialtone;local-only
---partHandle=4 is created.---

SEND: INVITE sip:Alice@xxxxxxxxxxxxxxx:35060 SIP/2.0

addpart 1 1
createconv
---convHandle=3 is created.---

addpart 3 1
volume 75
gain 75
createremote 3 <sip:Carol@repro>
---partHandle=5 is created.---

addpart 3 5
destroypart 4
removepart 1 1

=== onParticipantDestroyed: handle=4 ===

SEND: INVITE sip:Carol@repro SIP/2.0

=== onParticipantAlerting: handle=5 msg=SipResp: 180
tid=2e63bc56165ed57d cseq=INVITE contact=Carol@xxxxxxxxxxxxxxx:55060 /
1 from(wire) ===

createmedia 1 tone:ringback;local-only
---partHandle=6 is created.---

addpart 1 1

=== onParticipantConnected: handle=5 msg=SipResp: 200
tid=2e63bc56165ed57d cseq=INVITE contact=Carol@xxxxxxxxxxxxxxx:55060 /
1 from(wire) ===

destroypart 6
removepart 1 1

=== onParticipantDestroyed: handle=6 ===

redirectTo 2 5

SEND: REFER sip:Alice@xxxxxxxxxxxxxxx:35060 SIP/2.0

=== onParticipantTerminated: handle=5 ===

createmedia 1 tone:busy;local-only
---partHandle=7 is created.---

addpart 1 1

SEND: SIP/2.0 200 OK

=== onParticipantDestroyed: handle=5 ===

removepart 3 5
destroyconv 3

=== onConversationDestroyed: handle=3 ===

SEND: SIP/2.0 200 OK

=== onParticipantRedirectSuccess: handle=2 ===

destroypart 7
removepart 1 1
destroyconv 2

=== onParticipantDestroyed: handle=7 ===

SEND: BYE sip:Alice@xxxxxxxxxxxxxxx:35060 SIP/2.0

=== onParticipantTerminated: handle=2 ===
=== onConversationDestroyed: handle=2 ===
=== onParticipantDestroyed: handle=2 ===
=== onConversationDestroyed: handle=1 ===
=== onParticipantDestroyed: handle=1 ===

//////////////////////////////////////////////////////////////////
// operations on Carol
//////////////////////////////////////////////////////////////////

echocancel 1
autogain 1
noisereduction 1
createlocal
---partHandle=1 is created.---

createconv
---convHandle=1 is created.---

=== onIncomingParticipant: handle=2auto=0 msg=SipReq:  INVITE
Carol@xxxxxxxxxxxxxxx:55060 tid=7cba3d43b39e2260 cseq=INVITE
contact=Bob@xxxxxxxxxxxxxxx:45060 / 1 from(wire) ===

createconv
---convHandle=2 is created.---

addpart 2 1
volume 75
gain 75
addpart 2 2
alert 2 noearly
createmedia 1 tone:ring;local-only
---partHandle=3 is created.---

addpart 1 1

SEND: SIP/2.0 180 Ringing

answer 2
addpart 2 1
volume 75
gain 75
destroypart 3
removepart 1 1

SEND: SIP/2.0 200 OK

=== onParticipantDestroyed: handle=3 ===

SEND: BYE sip:Bob@xxxxxxxxxxxxxxx:45060 SIP/2.0

SEND: SIP/2.0 200 OK

SEND: INVITE sip:Alice@xxxxxxxxxxxxxxx:35060 SIP/2.0

SEND: SIP/2.0 491 Request Pending

SEND: INVITE sip:Alice@xxxxxxxxxxxxxxx:35060 SIP/2.0

//////////////////////////////////////////////////////////////////


Regards,




2010/1/27 Scott Godin <sgodin@xxxxxxxxxxxxxxx>:
> Hello,
>
> Thanks for the good detail on the SIP signalling portion of your
> issue.  However I have a couple questions on other important parts of
> your setup:
> 1.  Are you using a LocalParticipant in the original conversation
> between A and B?  In the 2nd call between B and C?
> 2.  After the call from B to C is placed - what is your conversation
> setup?  Do you have both A and C in the same conversation?  or are the
> two parties in separate Conversations?  If separate - which
> conversation has the Local Participant, if any?
> 3.  Are you using testUA to produce this scenario?  If so - can you
> please send over the series of commands you are using.
> 4.  Can you please provide a wireshark trace of this - it will help to
> be able to see the contents of the SDP bodies.
> 5.  I'm assuming A, B and C are all using recon - is this correct?
>
> Thanks,
> Scott
>
> On Tue, Jan 26, 2010 at 8:01 AM, Yamato Kira <coordinator.kira@xxxxxxxxx> wrote:
>> Hi,
>>
>> I am using resiprocate-1.6.
>>
>> I tried Transfer-Attended sequence with a sip proxy server(repro) and my
>> SIP-UA applications which using recon.
>>
>> A...B...C
>> |...|...|
>> |<=>|...| two party call between A and B.
>> |...|<=>| two party call between B and C.
>> :...:...:
>> |...|...| B execute recon::ConversationManager::rediretToParticipant(A,C)
>> |<R-|...| B send REFER(repleces) to A.
>> |-INV-->| A send INVITE(repleces) to C.
>> |<-200--| C respond 200OK(INVITE) to A.
>> :...:...:
>>
>> see also
>> http://tools.ietf.org/html/rfc5359#section-2.5
>>
>>
>> I use the recon::ConversationManager::rediretToParticipant().
>> But my application using RECON acted two motions not intended.
>>
>>
>> === 1st problem ===
>> This may be not problem.
>>
>> - After receiving INVITE with Replaces header,
>>  my applications which confirmed new session replaced sent re-INVITEs and
>> 491 responses each other.
>>
>> A...B...C
>> :...:...:
>> |...|...| B execute rediretToParticipant(A,C)
>> |<R-|...| B send REFER(repleces) to A.
>> |-INV-->| A send INVITE(repleces) to C.
>> |<-200--| C respond 200OK(INVITE) to A.
>> |-INV-->| A send re-INVITE to C.
>> |<-INV--| C send re-INVITE to A.
>> |-491-->| A respond 491 Request Pending to C.
>> |<-491--| C respond 491 Request Pending to A.
>> :...:...:
>>
>> These re-INVITEs caused by unhold() in
>> RemoteParticipant::stateTransition(Connected);
>> This unhold() is called because mPendingRequest.mType is Unhold.
>> mPendingRequest.mType is set according to the following timing.
>>
>> + receive INVITE(repleces)
>> .+ new RemoteParticipant is created. RemoteParticipant::mLocalHold is set
>> true by constructor.
>> .+ RemoteParticipant::onNewSession(Server)
>> ..+ participantToReplace->replaceWithParticipant(this);
>> ...+ Participant::copyConversationsToParticipant()
>> ....+ RemoteParticipant::addToConversation()
>> .....+ if(mLocalHold && !conversation->shouldHold())
>> .....+ unhold()
>> ......+ mPendingRequest.mType = Unhold;
>>
>> or
>>
>> + receive REFER(replaces)
>> .+ RemoteParticipant::onRefer()
>> ..+ new RemoteParticipant is created. RemoteParticipant::mLocalHold is set
>> true by constructor.
>> ..+ replaceWithParticipant(participant);
>> ...+ Participant::copyConversationsToParticipant()
>> ....+ RemoteParticipant::addToConversation()
>> .....+ if(mLocalHold && !conversation->shouldHold())   // mLocalHold is
>> true.
>> .....+ unhold()
>> ......+ mPendingRequest.mType = Unhold;
>>
>>
>> I have a try to insert tentative code into RemoteParticipant.cxx.
>>
>> --------
>> RemoteParticipant::onNewSession(ServerInviteSessionHandle...
>> {
>> :
>> +        mLocalHold = false;                    // XXX to avoid unhold()
>>         participantToReplace->replaceWithParticipant(this);      // adjust
>> conversation mappings
>> :
>> }
>> --------
>>
>> --------
>> RemoteParticipant::onRefer(InviteSessionHandle...
>> {
>> :
>> +     participant->mLocalHold = false;          // XXX to avoid unhold()
>>      replaceWithParticipant(participant);      // adjust conversation
>> mappings - do this after buildSdpOffer, so that we have a bridge port
>> :
>> }
>> --------
>>
>> Then, the SIP sequence has changed as follows.
>>
>> A...B...C
>> :...:...:
>> |...|...| B execute rediretToParticipant(A,C)
>> |<R-|...| B send REFER(repleces) to A.
>> |-INV-->| A send INVITE(repleces) to C.
>> |<-200--| C respond 200OK(INVITE) to A.
>>
>>
>> But, I am suspecting that my tentative source code is impropriety.
>>
>>
>>
>> === 2nd problem ===
>>
>> - After receiving INVITE with Replaces header,
>>  my applications established a new session between A and C, nevertheless
>> they became silent.
>>
>> A...B...C
>> :...:...:
>> |...|...| B execute rediretToParticipant(A,C)
>> |<R-|...| B send REFER(repleces) to A.
>> |-INV-->| A send INVITE(repleces) to C.
>> |<-200--| C respond 200OK(INVITE) to A.
>> |-INV-->| A send re-INVITE to C.
>> |<-INV--| C send re-INVITE to A.
>> |-491-->| A respond 491 Request Pending to C.
>> |<-491--| C respond 491 Request Pending to A.
>> :...:...:
>> |-RTP-->|
>> |-RTP-->| RTP packets flowed only to one direction.
>> |-RTP-->|
>> :...:...:
>>
>> Not only A but also C are silent.
>>
>>
>> I am thinking that RemoteParticipant::adjustRTPStreams() and
>> RemoteParticipant::replaceWithParticipant() may be correlating with this
>> problem.
>> But, I am puzzled.
>>
>> Following is a part of the log of adjustRTPStreams and RemoteParticipant
>> handles.
>> Could anyone help me?
>>
>>
>>
>> A...B...C
>> |...|...|
>> |<=>|...| two party call between A and B.
>> :...:...:
>> |...|-->| B send initial INVITE to C.
>>
>>
>> DEBUG and INFO Logs in C:
>> RemoteParticipant.cxx:71 | RemoteParticipant created (UAS or forked leg),
>> handle=14
>> RemoteParticipant.cxx:1786 | onNewSession(Server): handle=14
>> RemoteParticipant.cxx:1989 | onOffer: handle=14
>> :
>> Conversation.cxx:224 | Participant handle=14 added to conversation handle=5
>> (BridgePort=3)
>> BridgeMixer.cxx:37 | calculatingMixWeigthsForParticipant, handle=14,
>> bridgePort=3
>> RemoteParticipant.cxx:565 | RemoteParticipant::unhold request: handle=14
>> RemoteParticipant.cxx:1466 | adjustRTPStreams: handle=14, found media line
>> in local sdp, mediaType=2, transportType=3, numConnections=1, port=51010
>> RemoteParticipant.cxx:1698 | adjustRTPStreams: handle=14
>> RemoteParticipant.cxx:1746 | adjustRTPStreams: handle=14
>> RemoteParticipant.cxx:1756 | adjustRTPStreams: handle=14, receiving...
>>
>>
>> A...B...C
>> :...:...:
>> |...|<--| C respond 200OK(INVITE) to B
>>
>>
>> RemoteParticipant.cxx:1891 | onConnected: handle=14, SipResp: 200
>> RemoteParticipant.cxx:253 | RemoteParticipant::stateTransition of handle=14
>> to state=Connected
>>
>>
>> A...B...C
>> :...:...:
>> |...|...| B execute recon::ConversationManager::rediretToParticipant(A,C)
>> |<R-|...| B send REFER(repleces) to A.
>> |-INV-->| A send INVITE(repleces) to C.
>>
>> DEBUG and INFO Logs in C:
>> RemoteParticipant.cxx:71 | RemoteParticipant created (UAS or forked leg),
>> handle=16
>> RemoteParticipant.cxx:1786 | onNewSession(Server): handle=16
>> RemoteParticipant.cxx:1798 | onNewSession(Server): handle=16, to replace
>> handle=14
>> :
>> Conversation.cxx:224 | Participant handle=14 added to conversation handle=5
>> (BridgePort=-1)//////// bridgePort=-1 is correct value ??
>> BridgeMixer.cxx:37 | calculatingMixWeigthsForParticipant, handle=14,
>> bridgePort=-1         //////// bridgePort=-1 is correct value ??
>> RemoteParticipant.cxx:565 | RemoteParticipant::unhold request: handle=14
>> :
>> RemoteParticipant.cxx:253 | RemoteParticipant::stateTransition of handle=14
>> to state=Replacing
>> RemoteParticipant.cxx:1989 | onOffer: handle=14, SipReq:
>> :
>> RemoteParticipant.cxx:1466 | adjustRTPStreams: handle=14, found media line
>> in local sdp, mediaType=2, transportType=3, numConnections=1, port=51012
>> RemoteParticipant.cxx:1698 | adjustRTPStreams: handle=14
>> RemoteParticipant.cxx:1746 | adjustRTPStreams: handle=14
>> RemoteParticipant.cxx:1756 | adjustRTPStreams: handle=14, receiving...
>> RemoteParticipant.cxx:253 | RemoteParticipant::stateTransition of handle=14
>> to state=Connecting
>>
>>
>> A...B...C
>> :...:...:
>> |<-200--| C respond 200OK(INVITE) to A.
>>
>>
>> DEBUG and INFO Logs in C:
>> RemoteParticipant.cxx:1891 | onConnected: handle=14, SipResp: 200
>> RemoteParticipant.cxx:253 | RemoteParticipant::stateTransition of handle=14
>> to state=Connected
>> RemoteParticipant.cxx:565 | RemoteParticipant::unhold request: handle=14
>> RemoteParticipantDialogSet.cxx:601 | setProposedSdp: handle=14,
>> proposedSdp=v=0
>> RemoteParticipant.cxx:1466 | adjustRTPStreams: handle=14, found media line
>> in local sdp, mediaType=2, transportType=3, numConnections=1, port=51012
>> RemoteParticipant.cxx:1631 | adjustRTPStreams: handle=14, mediaDirection=3,
>> remoteIp=, remotePort=0
>> RemoteParticipant.cxx:1722 | adjustRTPStreams: handle=14, stop sending.
>> RemoteParticipant.cxx:1756 | adjustRTPStreams: handle=14, receiving...
>> RemoteParticipant.cxx:253 | RemoteParticipant::stateTransition of handle=14
>> to state=Unholding
>>
>> A...B...C
>> :...:...:
>> |-INV-->| A send re-INVITE to C.
>> |<-INV--| C send re-INVITE to A.
>> |-491-->| A respond 491 Request Pending to C.
>> |<-491--| C respond 491 Request Pending to A.
>> :...:...:
>> |-RTP-->|
>> |-RTP-->| RTP packets flowed only to one direction.
>> |-RTP-->|
>> :...:...:
>>
>> RemoteParticipant.cxx:1975 | onAnswer: handle=14, SipResp: 200
>> RemoteParticipant.cxx:1466 | adjustRTPStreams: handle=14, found media line
>> in local sdp, mediaType=2, transportType=3, numConnections=1, port=51012
>> RemoteParticipant.cxx:1698 | adjustRTPStreams: handle=14
>> RemoteParticipant.cxx:1756 | adjustRTPStreams: handle=14, receiving...
>> RemoteParticipant.cxx:253 | RemoteParticipant::stateTransition of handle=14
>> to state=Connected
>>
>>
>>
>> Regards,
>>
>> _______________________________________________
>> recon-devel mailing list
>> recon-devel@xxxxxxxxxxxxxxx
>> List Archive: http://list.resiprocate.org/archive/recon-devel/
>>
>