Channel problem in app

[GoogleCodeExporter]

What version of the product are you using? On what operating system?
Asterisk 1.4
RHEL 3.9 Update 9
LoquendoSS 7.0
uni-ast-package-0.2.0 (with new revision 1544)

Please provide any additional information below.
I have an error, when I try to use simultaneously more channels 
license than I have. 
For example for a license with 3 channels, I do 4 phone calls, the 4th 
call waits to a license, 
but when the 1st call finish, instead off init the 4th call TTS, the 
Asterisk service comes down. 

Original issue reported on code.google.com by assantas...@gmail.com on 1 Mar 2010 at 3:13

Attachments:

• extensions_01032010.txt
• mrcp_01032010.conf
• Asterisk_log_01032010.txt
• gdb_01032010.txt

[GoogleCodeExporter]

Please try with the latest SVN HEAD version and provide feedback. I fixed an
initialisation issue.

Original comment by thirion...@gmail.com on 1 Mar 2010 at 3:43

[GoogleCodeExporter]

Hi Assanta,

As far as I understand, you tried r1544 revision, which already contained 
Derik's
fix, but the issue still persisted.

Looking at the Asterisk's logs attached and back to the app_unimrcp code, it 
seems
I've found another a bit suspicious thing, which we probably should investigate
closer with Derik.

[Feb 19 12:03:07] ERROR[21547]: app_unimrcp.c:1966 speech_channel_destroy: 
(TTS-13)
Failed to destroy channel. Continuing 

This is indeed an error condition. Most probably, the request was timed out 
without
any response and channel was destroyed. It's dangerous as channel still can be 
used
in client stack. Suppose that response was eventually received, but channel and
memory pool had been already destroyed by that time. The result is clear...

I'm not sure why 10 sec wasn't enough, but I'd strongly suggest to increase the
timeout at least for now. Normally it shouldn't ever expire.

Assanta, please try to increase it to say 60 sec and see if it helps.
app_unimrcp.c line:44
#define SPEECH_CHANNEL_TIMEOUT_USEC             (60 * 1000000)

If anything goes wrong please provide debug output enabled logs.

Original comment by achalo...@gmail.com on 2 Mar 2010 at 12:52

• Added labels: Component-Asterisk, OpSys-Linux, Priority-Medium, Type-Defect

[GoogleCodeExporter]

Hi
The problem has change, but I continue with the Asterisk service coming down.
The problem now is the "null" on the line: 
speech_on_session_terminate: ((null)) Destroying MRCP session

This is what I suppose:
Imagine a TTS of 30 seconds, and the PTIME in 20 seconds, 4 calls at the same 
time 
starts, the first three calls start with the TTS, and the fourth one wait, 
after the 
first 10 seconds UNIMRCP send a channel destroy of the fourth call, then when 
Loquendo finish with the first call advise that is free, and then UNIMRCP try 
to 
destroy a channel that is already destroyed.
I attach the asterisk log and the gdb with ERROR.
I Also attach Asterisk log of a normal call without error (here you can see 
the "speech_on_session_terminate: (TTS-1) Destroying MRCP session" line)

Why 10 seconds? at first I thought about de ptime, but it doesn't matter the 
ptime, 
always destroy the chanel after 10 seconds.

Thanks
Assanta

Original comment by assantas...@gmail.com on 2 Mar 2010 at 5:40

Attachments:

• Asterisk_log_02032010_ERROR.txt
• gdb_02032010_ERROR.txt
• Asterisk_log_02032010_OK.txt

[GoogleCodeExporter]

Hi achaloyan
I hadn't read your message, it seems the problem is clear
I suppose that with the SPEECH_CHANNEL_TIMEOUT_USEC change I won't have 
problems if 
the TTS text is less than 60 seconds, but if is more I'll have the same problem.
Anyway I'll try tomorrow and I feedback.

Thanks

Original comment by assantas...@gmail.com on 2 Mar 2010 at 5:54

[GoogleCodeExporter]

Hi
What I supposed yesterday. With a SPEECH_CHANNEL_TIMEOUT_USEC=60 seconds and a 
TTS 
text more than 60 seconds, I have the same problem.
Now there are less problems because is no normal to have TTS with more than 60 
seconds, but the risk is very high, because the Asterisk Service goes down.

One question, is there any memory problem or something like this, having a high 
SPEECH_CHANNEL_TIMEOUT_USEC?

The revision I have installed in right now is the revision 1552

I attach you the log, from the channel destroy to the end, but is like the 
others 
logs.

Thanks
Assanta

Original comment by assantas...@gmail.com on 3 Mar 2010 at 3:36

Attachments:

• Asterisk_log_03032010.txt

[GoogleCodeExporter]

SPEECH_CHANNEL_TIMEOUT_USEC is mostly used when waiting for a response from the 
MRCP
server that should take a short amount of time.  
For example:
  1. Opening a session
  2. Waiting for IN PROGRESS
  3. Waiting for an audio frame
  4. Waiting for STOP to process
  5. Waiting for a session to be destroyed

In your latest log, it appears the session was being destroyed before it 
received IN
PROGRESS. This is not good as neither speech_channel_destroy() nor
speech_channel_stop() was designed to handle that scenario.  

Original comment by cmrie...@gmail.com on 3 Mar 2010 at 4:36

[GoogleCodeExporter]

Hi cmrienzo
This is the matter, the client send a SPEAK but the server hasn't free licence 
so 
wait until a free license. Before the license is released, the 
SPEECH_CHANNEL_TIMEOUT_USEC time pass, so "speech_channel_destroy()" appears. I 
don't know why channel_destroy instead channel_stop, it could be a UniMRCP 
problem?

Another question:
The server receive the SPEAK and doesn't have free license, so waits. This is 
normal? or must send for example a PENDING o smth like this?

Regards
Assanta

Original comment by assantas...@gmail.com on 3 Mar 2010 at 5:29

[GoogleCodeExporter]

Hi Assanta,

Honestly, I don't like the licensing scheme your server uses. It's simply not
convenient enough. I still don't think from the perspective of current
implementation. Perhaps, both mod_unimrcp (FreeSWITCH) and app_unimrcp 
(Asterisk)
should be a bit enhanced not to crash whatever happens, but server still behaves
irrelevant to me.

IN-PROGRESS response should be sent as soon as possible. If all the licenses are
exhausted, the server SHOULD respond with COMPLETE and failure status code. 
That's it!

Thanks for the issue report,
Arsen

Original comment by achalo...@gmail.com on 3 Mar 2010 at 5:54

• Changed state: Accepted

[GoogleCodeExporter]

Thanks for the clarification, Chris.

I wanted to discuss a few things with you and Derik on conceptual level.
The topic is request timeouts.
Every request from application to client stack should be acknowledged with one 
and
only one response. Ideally, there should be no request timeouts in application 
level
or that timeout should be long enough and should never expire. Though there was 
a
vulnerability in client stack, which I have been trying to address now. There 
were no
request timeouts in RTSP and MRCPv2 client stacks. I have been working on timers
related stuff now and will post to the group with more details when done 
(really soon).

In the meantime, I hope you'll reconsider this stuff a bit in your modules,
especially timeouts used on session destroy. It's really dangerous...

Any ideas or thoughts are welcome.

Original comment by achalo...@gmail.com on 3 Mar 2010 at 6:16

[GoogleCodeExporter]

Hello Arsen,

I never expect a timeout to occur- it is an indication of a serious problem. 
However, I don't want my call to get stuck due to a server problem.  If UniMRCP 
can
guarantee that I always get a response (maybe the lib deals with timeouts) then 
it
would be OK to let the app code wait forever.

Original comment by cmrie...@gmail.com on 3 Mar 2010 at 7:11

[GoogleCodeExporter]

Hello Chris,

I agree with you and my intent is client stack should have its internal 
timeouts and
guarantee a response back to application.

Original comment by achalo...@gmail.com on 3 Mar 2010 at 8:03

[GoogleCodeExporter]

Hi Arsen
Could be, we are talking about different behaviors. I'm talking about I phone 
call 
that haven't free license and must wait until a license is free and you are 
talking 
about a phone call that haven't free license and hang up, isn't it?
I could use my server in that way, if there aren't free licenses responding 
with 
COMPLETE, and this works ok, but is not what i want, i just want to wait until 
the 
license is released.
My question was if the performance of the server about not answer anything 
could 
cause UniMRCP failure and if must answer with a PENDING or smth like this, but 
not 
with a COMPLETE, because I want to wait until license released.
Anyway I think is a good idea the posibility of the TIMEOUT, wait for a free 
license, but not eternally, the problem is that this doesn't works, because 
when the 
time finish the service goes down.

One clarificatión, I'm using MRCPv1, I post it to the group, but I hadn't post 
here.

Best Regards
Assanta

Original comment by assantas...@gmail.com on 4 Mar 2010 at 10:43

[GoogleCodeExporter]

Hi Assanta,

I think I clearly understand what is going on. You're trying to serve M callers 
using
N licenses, where M > N. Not a bad idea :)
I understand this approach, but from conceptual view point I'd implement it 
either in
client stack or better in actual application, but not in MRCP server. It still 
looks
not so convenient to me and I wonder why they ever implemented it. Anyway, I'm 
glad
the server supports both options.

As of PENDING response, server cannot use PENDING for this particular case, as
obviously, there is no IN-PROGRESS SPEAK request in the scope of the same 
session.
Please note this is a new call/session and all the concurrent SPEAK requests 
are done
in the scope of their own MRCP sessions.

For now, I think you can safely increase SPEECH_CHANNEL_TIMEOUT_USEC to be near 
to
infinity and everything should work the way you need. In the meantime, I'm 
working on
a few related enhancements in client stack, which should allow Chris and Derik 
to
make this routine smarter in applications.

Hopefully everything is clear now and best regards to you too.

Original comment by achalo...@gmail.com on 4 Mar 2010 at 1:25

[GoogleCodeExporter]

Hi Arsen

everything is clear, thanks for your work and your help

I'll be waiting for the next version :-) Meanwhile I'll use a high 
SPEECH_CHANNEL_TIMEOUT_USEC

Assanta

Original comment by assantas...@gmail.com on 4 Mar 2010 at 3:32

[GoogleCodeExporter]

app_unimrcp now doesn't allow timeouts during a speech_channel_destroy. 
Hopefully
this helps.

Original comment by thirion...@gmail.com on 10 Mar 2010 at 8:11

[GoogleCodeExporter]

Forgot to ask that you could please verify no more crashes on Asterisk with the
latest fixes.

Original comment by thirion...@gmail.com on 10 Mar 2010 at 12:18

• Changed state: Fixed

[GoogleCodeExporter]

Hi

Perfect!!!! I've tested many times and no more crashes, here the log of the 4th 
call, for a TTS with 30 seconds, with 3 licenses and 4 calls at the same time.

[Mar 11 12:39:26] DEBUG[7894]: app_unimrcp.c:1970 speech_channel_destroy: 
Destroying 
speech channel: Name=TTS-3, Type=SYNTHESIZER, Codec=PCMU, Rate=8000
[Mar 11 12:39:26] DEBUG[7894]: app_unimrcp.c:4147 unimrcp_log: Signal Message 
to 
[MRCP Client] [4;0]
[Mar 11 12:39:26] DEBUG[7894]: app_unimrcp.c:1988 speech_channel_destroy: 
(TTS-3) 
Waiting for MRCP session to terminate
[Mar 11 12:39:36] WARNING[7894]: app_unimrcp.c:1993 speech_channel_destroy: 
(TTS-3) 
MRCP session has not terminated after 10000 ms
[Mar 11 12:39:45] DEBUG[7894]: app_unimrcp.c:881 audio_queue_destroy: (TTS-3) 
audio 
queue destroyed
[Mar 11 12:39:45] NOTICE[7894]: app_unimrcp.c:2013 speech_channel_destroy: 
(TTS-3) 
Audio queue destroyed
[Mar 11 12:39:45] DEBUG[7894]: app_unimrcp.c:2055 speech_channel_destroy: 
Destroyed 
speech channel complete
    -- Executing [971570358@default2:3] Hangup("SIP/assanta-08f02528", "") in new 
stack
  == Spawn extension (default2, 971570358, 3) exited non-zero on 'SIP/217.149.155.51-
08f02528'
    -- Executing [h@default2:1] NoOp("SIP/assanta-08f02528", "2010-03-11 12:39:15-
2010-03-11 12:39:15-") in new stack

Assanta

Original comment by assantas...@gmail.com on 11 Mar 2010 at 12:17

[GoogleCodeExporter]

That's greate news!

Original comment by thirion...@gmail.com on 11 Mar 2010 at 12:33

• Changed state: Verified