Skip to main content

problem with call-controler2

18 replies [Last post]
silviud
Offline
Joined: 2007-03-26
Points: 0

Hello,

After making some calls to test the different cases of the call-control2 example, it seems that more than one Sbb entity handle the same call. Thus I get the same ontput from 2 or more Sbb entities.

INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - --> CallID: d1f56e500d95477b8370c62d79cad3ed
INFO - ########## BLOCKING ADDRESS: sip:silviu
INFO - ########## BLOCKING ADDRESS: sip:silviu
INFO - ########## BLOCKING FOR URI: sip:victor@nist.gov
INFO - ########## BLOCKING FOR URI: sip:victor@nist.gov
INFO - ########## CALL FORWARDING SBB: FILTERED BY ANCESTOR ##########
INFO - ########## CALL FORWARDING SBB: FILTERED BY ANCESTOR ##########
INFO - ########## VOICE MAIL SBB: INVITE ##########
INFO - ########## VOICE MAIL SBB: INVITE ##########
INFO - ########## VOICE MAIL SBB: INVITE ##########
INFO - ########## VOICE MAIL SBB: FILTERED BY ANCESTOR ##########
INFO - ########## VOICE MAIL SBB: FILTERED BY ANCESTOR ##########
INFO - ########## VOICE MAIL SBB: FILTERED BY ANCESTOR ##########
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - ########## BLOCKING ADDRESS: sip:silviu
INFO - ########## BLOCKING ADDRESS: sip:silviu
INFO - ########## BLOCKING FOR URI: sip:victor@nist.gov
INFO - ########## BLOCKING FOR URI: sip:victor@nist.gov
INFO - ########## CALL FORWARDING SBB: FILTERED BY ANCESTOR ##########
INFO - ########## CALL FORWARDING SBB: FILTERED BY ANCESTOR ##########
INFO - ########## VOICE MAIL SBB: INVITE ##########
INFO - ########## VOICE MAIL SBB: INVITE ##########
INFO - ########## VOICE MAIL SBB: INVITE ##########
INFO - ########## VOICE MAIL SBB: FILTERED BY ANCESTOR ##########
INFO - ########## VOICE MAIL SBB: FILTERED BY ANCESTOR ##########
INFO - ########## VOICE MAIL SBB: FILTERED BY ANCESTOR ##########

Is this normal? How can I correct this?

Thank you.

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
silviud
Offline
Joined: 2007-03-26
Points: 0

receive dtmf issue came up

torosvi
Offline
Joined: 2005-07-20
Points: 0

OK,

I will try to reproduce it on the weekend.

Cheers,

Victor

torosvi
Offline
Joined: 2005-07-20
Points: 0

Hello,

I have tested it and I could not reproduce it. It works for me. I have to say that I have a mobicents release from around 6 months ago.

Taking into account the behaviour that you say it is happening to you, I think that if you can listen the message, that means that the session is still opened, and the session was opened to listen DTMF digits, so it should listen the digits after 60 seconds as well.

As I have said, it works for me, but we can dig in it to know what it is happening.

Cheers,

Victor

alexis84
Offline
Joined: 2007-08-27
Points: 0

Hello!

I have the same problem as silviud. The DtmfEvent is not fired after the second announcement. Does anyone know where is the problem?

I noticed another problem with VoiceMailSbb: if the user (x-lite in my case) hungs up (BYE Request) during the second announcement I get the following error:

16:08:11,102 INFO [VoiceMailSbbImpl] ########## VOICE MAIL SBB: BYE ##########
16:08:11,174 INFO [MediaListener] ...transmission ended.
16:08:11,174 INFO [STDOUT] **** LOCALHOST = /10.0.2.35
16:08:11,174 INFO [MediaResourceAdaptor] Resource adaptor delivering event:/n 58
16:08:11,175 INFO [EventRouterImpl] number of Active services = 4
16:08:11,178 INFO [ActivityContext] ActivityContext[ID:11d1def534ea1be0:3dc87857:114db05a707:-7ea9],
SbbAttachmentSet: [100_11d1def534ea1be0:3dc87857:114db05a707:-7eac],
Transaction[ID:TransactionImpl:XidImpl [FormatId=257, GlobalId=imsvisited//878, BranchQual=]]
16:08:11,180 INFO [VoiceMailSbbImpl] ########## VOICE MAIL SBB: onEndMediaStreamEvent ##########
16:08:11,283 INFO [MediaSessionImpl] Track 0 is set to transmit as:
16:08:11,283 INFO [MediaSessionImpl] ULAW/rtp, 8000.0 Hz, 8-bit, Mono, FrameSize=8 bits
16:08:11,341 INFO [VoiceMailSbbImpl] ########## VOICE MAIL SBB: byeRequestOkResponse ##########
16:08:11,348 INFO [STDOUT] from="10.0.2.35:7888"
to="10.0.5.42:18614"
time="1189087691347"
isSender="true"
transactionId="z9hg4bk-d87543-3d38555375719a3f-1--d87543-"
callId="ZDI5ZTZmNDExMTFkZDY2ZjMzMzYyMTAzYTgxOWVmZDQ."
firstLine="SIP/2.0 200 OK"
>
Via: SIP/2.0/UDP 10.0.5.42:18614;received=10.0.5.42;branch=z9hG4bK-d87543-3d38555375719a3f-1--d87543-;rport=18614
From: "torosvi" ;tag=6575ae5f
Call-ID: ZDI5ZTZmNDExMTFkZDY2ZjMzMzYyMTAzYTgxOWVmZDQ.
CSeq: 2 BYE
Contact:
To: "vmail" ;tag=12345SomeTagID6789
Content-Length: 0

]]>

16:08:11,350 INFO [ActivityContext] ActivityContext[ID:11d1def534ea1be0:3dc87857:114db05a707:-7ea8],
SbbAttachmentSet: [100_11d1def534ea1be0:3dc87857:114db05a707:-7eac],
Transaction[ID:TransactionImpl:XidImpl [FormatId=257, GlobalId=imsvisited//872, BranchQual=]]
16:08:11,517 ERROR [EventRouterImpl] Failure while routing event; second phase. Event Posting [eventTypeId:EventTypeID[org.mobicents.slee.media.EndMediaStream#org.mobicents.media#1.0], #58, event:EndMediaStreamEvent[309603259], activity:org.mobicents.slee.resource.media.ra.MediaActivityHandle@59303a04, address:IP: 10.0.2.35]
java.lang.NullPointerException
at org.mobicents.slee.resource.media.ra.MediaSessionImpl.initSession(MediaSessionImpl.java:238)
at org.mobicents.slee.resource.media.ra.MediaSessionImpl.createTransmitterReceiver(MediaSessionImpl.java:302)
at org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbb.checkDtmfDigit(VoiceMailSbb.java:590)
at org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbb.onEndMediaStreamEvent(VoiceMailSbb.java:379)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.mobicents.slee.runtime.SbbEntity.invokeEventHandler(SbbEntity.java:1389)
at org.mobicents.slee.runtime.EventRouterImpl.routeQueuedEvent(EventRouterImpl.java:1098)
at org.mobicents.slee.runtime.EventRouterImpl.access$100(EventRouterImpl.java:73)
at org.mobicents.slee.runtime.EventRouterImpl$EventExecutor.run(EventRouterImpl.java:167)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)
16:08:11,518 INFO [ActivityContext] ActivityContext[ID:11d1def534ea1be0:3dc87857:114db05a707:-7ea9],
SbbAttachmentSet: [100_11d1def534ea1be0:3dc87857:114db05a707:-7eac],
Transaction[ID:TransactionImpl:XidImpl [FormatId=257, GlobalId=imsvisited//878, BranchQual=]]
16:08:11,518 ERROR [EventRouterImpl] Caught RuntimeException in invoking SLEE originated invocation
java.lang.NullPointerException
at org.mobicents.slee.resource.media.ra.MediaSessionImpl.initSession(MediaSessionImpl.java:238)
at org.mobicents.slee.resource.media.ra.MediaSessionImpl.createTransmitterReceiver(MediaSessionImpl.java:302)
at org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbb.checkDtmfDigit(VoiceMailSbb.java:590)
at org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbb.onEndMediaStreamEvent(VoiceMailSbb.java:379)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.mobicents.slee.runtime.SbbEntity.invokeEventHandler(SbbEntity.java:1389)
at org.mobicents.slee.runtime.EventRouterImpl.routeQueuedEvent(EventRouterImpl.java:1098)
at org.mobicents.slee.runtime.EventRouterImpl.access$100(EventRouterImpl.java:73)
at org.mobicents.slee.runtime.EventRouterImpl$EventExecutor.run(EventRouterImpl.java:167)
at EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
at java.lang.Thread.run(Thread.java:595)

I can see that the function onEndMediaStreamEvent(EndMediaStreamEvent event, ActivityContextInterface aci) calls another function checkDtmfDigit(this.getDtmf()), which is incorrect in this case because of the previous statement this.setDtmf(NON_DIGIT);

This happens only if the second announcement is played. If the user hungs up during the first announcement the 'dtmf' CMP field is set and read correctly. What happens with 'dmtf' CMP field during the second announcement?

Help appreciated

Alex

silviud
Offline
Joined: 2007-03-26
Points: 0

sorry for my last intervention...

Before posting this, I thought twice :)

I was trying to change the VoiceMailSbb to do something like this: "Hello user, you have", count new messages, say the number, "new messages", "press 1 if you want to... 2 if you want to..., etc.". The problem is the dtmf doesn't reach the sbb even when using createTransmitterReceiver(..., ..., ..., true).

So, I stopped the server, started it again, but his time I deployed the original cc2 (without ANY line of my own), logged into x-lite with user torosvi, called vmail, let the first announcement play, waited, let the tryAgain announcement play, and THEN pressed a digit. => the DtmfEvent is not fired after. The tryAgain announcement comes again and again and the dtmf digits don't reach the VoiceMailSbb. This happens only after the second announcement. If I press a digit during or after the first announcement it works.

You can try to do this: call vmail, when you hear the WaitingDTMF announcement, press 3 (or something != 1,7,9), you get the "I didn't understand what you said" and after that it doesn't respond to any dtmf...

ivelin
Offline
Joined: 2003-07-13
Points: 0

sounds like the VoiceMail SBB logic for DTMF handling is buggy. Perfect opportunity for you to build confidence in your JSLEE skills by fixing it. We can help by reviewing the patch.

silviud
Offline
Joined: 2007-03-26
Points: 0

I looked at the logic for the scenario I mentioned for cc2:
user calls own voice mail, doesn't press anything during the first announcement, waits for the second announcement and presses a digit.

here's what's executed related to mediaSession:

[i]public void onInvite(javax.sip.RequestEvent event, VoiceMailSbbActivityContextInterface localAci) =>
audioFileURL = getClass().getResource(waitingDTMF);
receiveDtmf = true;

// SDP Description from the request
String sdp = new String(request.getRawContent());

// Creating Media Session
mediaSession = mediaProvider.getNewMediaSession();
// Setting Media Session
this.setMediaSession(mediaSession);

// Attaching session AC
ActivityContextInterface mediaSessionAci;
mediaSessionAci = mediaRaACIF.getActivityContextInterface(mediaSession);
mediaSessionAci.attach(this.getSbbLocalObject());

mediaSession.createTransmitterReceiver(sdp, audioFileURL, fileRcv, receiveDtmf);

public void onSessionResultEvent(SessionResultEvent event, ActivityContextInterface aci) =>
mediaSession = (MediaSession) aci.getActivity();
sendOkResponse();

public void onAckEvent(javax.sip.RequestEvent event, ActivityContextInterface aci) =>
mediaSession = this.getMediaSession();
mediaSession.startSession();

public void onEndMediaStreamEvent(EndMediaStreamEvent event, ActivityContextInterface aci) =>
mediaSession = (MediaSession) aci.getActivity();
... set timer ...

{Label 1}

public void onTimerEvent(TimerEvent event, ActivityContextInterface aci) =>
mediaSession = this.getMediaSession();
mediaSession.stopSession();
URL audioFileURL = getClass().getResource(tryAgain);
(1) mediaSession.createTransmitterReceiver(mediaSession.getSdpDescription(), audioFileURL, null, [i]true[/i]);

public void onSessionResultEvent(SessionResultEvent event, ActivityContextInterface aci) =>
mediaSession = (MediaSession) aci.getActivity();
mediaSession.startSession();

[b]-->> user presses digit => but no onDtmfEvent !!![/b]

public void onEndMediaStreamEvent(EndMediaStreamEvent event, ActivityContextInterface aci) =>
mediaSession = (MediaSession) aci.getActivity();
... set timer ...
[b]
-->> user presses digit => but no onDtmfEvent !!![/b]

go to {Label 1} => infinite loop until user sends BYE[/i]

The SBB does not receive DTMF Event. But it's not detached from the aci since it receives the EndMediaStreamEvent.
Is here anything wrong with the the createTransmitterReceiver for the tryAgain announcement in (1)? (receiveDtmf is true) shouldn't then the DtmfEvent be fired? The logic seems correct to me... Is there any chance that there is a problem with the MediaRA?

torosvi
Offline
Joined: 2005-07-20
Points: 0

Hi silviud,

I have been looking at your posts. It seems that you are digging into the cc2. That's great.
I will try to reproduce the bug. However, I am struggling to remember and I think that what you say worked for me. So, can you please give me step by step your test case? This is just to be sure that I understood it well an be able to reproduce it correctly.

Cheers,

Victor

silviud
Offline
Joined: 2007-03-26
Points: 0

Hi Victor!

This is what I did:
1. deployment of ra and cc2 (deploy-all)
2. used x-lite to log in with torosviI and called vmail.
3. waited for the menu announcement to play. (if I press a digit now, it works)
4. wait for the 60 sec to pass.
5. pressed a digit while the announcement was playing for the second time (or later)

=> no DTMF event was fired so it keeps playing the annoucement over and over. It does not react to DTMF.

I also tried to make am IVR of my own based on the example. Same problem. If I play an annoucement (createTransmitterReceiver) the DTMF is received. But after I play a second annoucement in the same media session, I'm not able to receive DTMFs any more.

Thank you!
Silviu

ivelin
Offline
Joined: 2003-07-13
Points: 0

this does not look normal. Tell us more about the environment and how we can reproduce it.

silviud
Offline
Joined: 2007-03-26
Points: 0

I have mobicents_cr3 server. I deployed the call-control2 example (including the RAs). I use x-lite and windows messenger to make calls from and to the users in the profile table. It seems that more than one sbb entiy responds to an event, thus generating the above output.

baranowb
Offline
Joined: 2006-01-09
Points: 0

Im not sure what You console dump shows, just a bunch of info() printouts. Whats the exact scenario?

Does this indicate that one event is delivered more than once?
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
INFO - --> CallID: 60a44444718141ca9565e0f75f91570f

?
Or is it some desired output to test something?

silviud
Offline
Joined: 2007-03-26
Points: 0

I tested on localhost making consecutive calls.
I posted the output for what happens after some of this calls. It seems that more entities respond to the same event.
In the initial event selector method I printed out the CallID.
public InitialEventSelector callIDSelect(InitialEventSelector ies) (SubscriptionProfileSbb.java)

I understood that this method is called whenever a new initial event is delivered to the SBBs. In this case it will be called for CallBlockingSbb, CallForwardingSbb, VoiceMailSbb. So, since I make only one call at a time, I should get 3 lines of the same output:

INFO - --> CallID: 60a44444718141ca9565e0f75f91570f

from each of the receiving SBBs. But there are more than 3...

It's the same with the output from the methods treating the INVITE event in the SBBs..
For example onInvite in CallBlockingSbb

INFO - ########## BLOCKING ADDRESS: sip:silviu
INFO - ########## BLOCKING ADDRESS: sip:silviu

If i make only one call, why is onInvite invoked twice in the same SBB ?

If you look at my first post, you will see, there are are 2 CallBlockingSbbs, 2 CallForwardingSbbs and 3 VoiceMailSbbs responding to ONE invite.

Please correct me if i did not understand the way it's supposed to work.

baranowb
Offline
Joined: 2006-01-09
Points: 0

> I tested on localhost making consecutive calls.
> I posted the output for what happens after some of
> this calls. It seems that more entities respond to
> the same event.
> In the initial event selector method I printed out
> the CallID.
> public InitialEventSelector
> r callIDSelect(InitialEventSelector ies)
> (SubscriptionProfileSbb.java)
>
Add "this" to determine which class prints, it can help to determimne cause
> I understood that this method is called whenever a
> new initial event is delivered to the SBBs. In this
> case it will be called for CallBlockingSbb,
> CallForwardingSbb, VoiceMailSbb. So, since I make
> only one call at a time, I should get 3 lines of the
> same output:
>
> INFO - --> CallID: 60a44444718141ca9565e0f75f91570f
>

correct, its more service based I think - call is made for each service
> from each of the receiving SBBs. But there are more
> than 3...
>
This shouldnt happen

> It's the same with the output from the methods
> treating the INVITE event in the SBBs..
> For example onInvite in CallBlockingSbb
>
> INFO - ########## BLOCKING ADDRESS: sip:silviu
> INFO - ########## BLOCKING ADDRESS: sip:silviu
>
> If i make only one call, why is onInvite invoked
> twice in the same SBB ?
>
> If you look at my first post, you will see, there are
> are 2 CallBlockingSbbs, 2 CallForwardingSbbs and 3
> VoiceMailSbbs responding to ONE invite.
>
> Please correct me if i did not understand the way
> it's supposed to work.

Nop, You are right, I wonder why this happens, I didnt notice such odd behaviour

Initial event selector methods all called each time event that is initial is going to be fired into slee.

SLEE contianers needs to determine where event has to be delivered. Not exactly sure now for what kind of object decission is made (granularity) but Im sure that for each service.
So if we have 3 services that have X event as initial - SLEE container calls each sevices initial event selector method on this event:
So CallBlock.selectCallId, CallForward.selectCallId... are called (order determined by service priority)

In our design - service chain, ies methods will always be called since services act independetly, and ies mechanism and custom convergence names are means of orchestrating them along with aci aliasing.

silviud
Offline
Joined: 2007-03-26
Points: 0

I started mobicents. deployed the call-control2 example, logged into x-lite with user torosvi, called vmail.

This is the output:

INFO - org.mobicents.slee.examples.callcontrol.forwarding.CallForwardingSbbImpl@1afc1de--> CallID: YWVkYTQ3MjIwN2I0NDBiMGFmY2E5ZjQyZjM0YjUzZDE.
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b--> CallID: YWVkYTQ3MjIwN2I0NDBiMGFmY2E5ZjQyZjM0YjUzZDE.
INFO - org.mobicents.slee.examples.callcontrol.blocking.CallBlockingSbbImpl@c2b8eb--> CallID: YWVkYTQ3MjIwN2I0NDBiMGFmY2E5ZjQyZjM0YjUzZDE.
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: INVITE ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: SessionResultEvent ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: sendOk ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@1e7bff8########## VOICE MAIL SBB: ACK ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@1e7bff8########## VOICE MAIL SBB: ACK ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: onDTMFEvent ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: onDTMFEvent ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: onEndMediaStreamEvent ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: onEndMediaStreamEvent ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: sendByRequest ##########
INFO - org.mobicents.slee.examples.callcontrol.voicemail.VoiceMailSbbImpl@5d8a8b########## VOICE MAIL SBB: sendByRequest ##########

It's not the same SBB entity responding to the events (which is ok, from what i read in the jslee specifications) but every line from the VoiceMailSbb is printed out twice. This happens always after the sendOk. (two ACKs are printed) If I make other calls, there will be more and more of the same output.
Do you also have this problem or is it my configuration?

ivelin
Offline
Joined: 2003-07-13
Points: 0

> If I make other calls, there will be more and more of the same output.

It might be that a VMail SBB entity is not detached when the call is over and is somehow stuck to an activity which is later used for another call. Seems low probability, but its possible if there is a fixed named activity reused between calls.

silviud
Offline
Joined: 2007-03-26
Points: 0

I found out what the cause of my problem was. In setSbbContext() I was adding a FileAppender to the logger without checking if there already is one attached. Thus more FileAppenders were writing to the same file.
I'm sorry to have wasted your time for this.

baranowb
Offline
Joined: 2006-01-09
Points: 0

Dont scare poeple like that any more :)