Timeout logs in Rivr Dialogues

Question

I am having timeout log entries for every Dialogue request in my Rivr VoiceXML application. I have watched the com.nuecho.rivr.core.channel.Timeout's in the doTurn methods and that's ok but I keep getting these logs, which are out of my code and so don't know how to catch and prevent the log file get full of them:

2015-09-21T19:03:02.29+0200 [App/0]      ERR [err] [Dialogue adef5e0c-4b6d-4f9a-9246-db8c3afadda9] INFO com.nuecho.rivr.dialogue - Dialogue ended.
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err] Exception in thread "Dialogue adef5e0c-4b6d-4f9a-9246-db8c3afadda9" 
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err] java.lang.RuntimeException: Timeout while sending final result.
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err]  at com.nuecho.rivr.core.channel.synchronous.SynchronousDialogueChannel$1.run(SynchronousDialogueChannel.java:242)
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err]  at java.lang.Thread.run(Unknown Source)
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err] Caused by: 
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err] com.nuecho.rivr.core.channel.Timeout: Timed-out in send() after 5 seconds (5000 ms) in [dialogue to controller]
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err]  at com.nuecho.rivr.core.channel.synchronous.SynchronousDialogueChannel.send(SynchronousDialogueChannel.java:405)
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err]  at com.nuecho.rivr.core.channel.synchronous.SynchronousDialogueChannel.access$600(SynchronousDialogueChannel.java:97)
2015-09-21T19:03:02.29+0200 [App/0]      ERR [err]  at com.nuecho.rivr.core.channel.synchronous.SynchronousDialogueChannel$1.run(SynchronousDialogueChannel.java:239)
2015-09-21T19:03:02.30+0200 [App/0]      ERR [err]  ... 1 more

Maybe I have to take any action with the com.nuecho.rivr.core.channel.Timeout I catch in my Dialogue code to prevent them (currently I just return with a

return new Exit("exit");

Thanks for any help

This is a bit odd. It means that the result of your dialog is not consumed by the DialogueServlet within 5 seconds delay. Is there much load on this server? — gawi, Sep 21 '15 at 21:10
No, not at all. This is the only app in the server. The Dialog does multiple things and maybe takes more than 5 seconds as has to prompt, record message, transcript it using voice to spice external API service, perform another API task on the transcription, and send back the results. All these tasks take probably more than 5 seconds but I guess this does not mean that the run() method in the Dialog is not consumed in 5 seconds. shall I include timestamps and log them through the run() method? Thanks a lot for your help. — icordoba, Sep 21 '15 at 21:20
This timeout is not dependent on the application code. The final send() is the step where the results from the dialogue (i.e. what you return from the Dialogue.run() method) are sent to the servlet through a Synchronous queue. I don't see why the DialogueServlet would take more than 5 seconds to do the take(). Do you actually returns something? Does your dialogue throw? — gawi, Sep 21 '15 at 21:33
There are 3 returns in the Dialogue and al do: return new Exit("exit"); The dialog was throwing com.nuecho.rivr.core.channel.Timeout (when some interaction timeout'ed because user did not say anything of hunged up for example) and I watched those exceptions and return the new Exit() object. Shall I leave the Timeout to propagate? — icordoba, Sep 21 '15 at 22:19
BTW, there is a new 1.0.7 version. In this release, the error handling has been improved a bit. So instead of receiving this error in the appserver log, you should get in the Rivr log. Maybe the new version might help you diagnose the problem more easily. — gawi, Jan 10 '16 at 19:04

gawi · Answer 1 · 2015-09-23T02:20:51.960

Probably, you are passing a time-out in the `DialogueUtils.doTurn() method. So you use:

doTurn(O outputTurn, DialogueContext<I,O> context, Duration timeout)

instead of the timeout-less version.

doTurn(O outputTurn, DialogueContext<I,O> context)

In some cases, your VoiceXML platform does not provide an answer to your dialogue within the specified time-out. This will trigger the Timeout exception. The dialogue will terminate and the last step of the dialogue (an exception in this case) cannot be consumed by the DialogServlet because there is no HttpServletRequest active in this case (the timeout occurs while VoiceXML platform is executing a document).

So ultimately, you don't want time-out to happen because it prevents you from controlling the dialogue. Time-out exists as safety nets. If for some reason the VoiceXML platform stop sending turns to your dialog, it has to terminate and free resources.

Note: Maybe it has nothing to do with what you are trying to accomplish but if you are doing a recording, you may want to set the maximumTime property of your Recordinginstead of setting a time-out value in doTurn(). If you want to put a time-out in doTurn() as a safety net, use a value which is bigger than the maximumTime property + the duration of all the prompts before recording. This way, the VoiceXML platform will raise an error and will send it back to your dialog. You are now able to control what happens next in your callflow. In this case you will have maxTime=true in your recording result.

I'd recommend that you check in your VoiceXmlInputTurn for a connection.disconnect.hangup event and exit the dialogue more cleanly if it is present.

Something like:

package com.nuecho.rivr.cookbook.dialogue;

import static com.nuecho.rivr.core.dialogue.DialogueUtils.*;

import com.nuecho.rivr.core.channel.*;
import com.nuecho.rivr.core.util.*;
import com.nuecho.rivr.voicexml.dialogue.*;
import com.nuecho.rivr.voicexml.turn.first.*;
import com.nuecho.rivr.voicexml.turn.input.*;
import com.nuecho.rivr.voicexml.turn.last.*;
import com.nuecho.rivr.voicexml.turn.output.*;
import com.nuecho.rivr.voicexml.turn.output.audio.*;

public class Dialogue implements VoiceXmlDialogue {

    @Override
    public VoiceXmlLastTurn run(VoiceXmlFirstTurn firstTurn, VoiceXmlDialogueContext context)
            throws Timeout, InterruptedException {

        try {
            Message message = new Message("message", new SpeechSynthesis("Hello World!"));
            VoiceXmlInputTurn inputTurn = doTurn(message, context, Duration.milliseconds(1200));
            if (VoiceXmlEvent.hasEvent(VoiceXmlEvent.CONNECTION_DISCONNECT_HANGUP, inputTurn.getEvents())) { 
                throw new CallerDisconnect(); 
            }
        } catch (CallerDisconnect callerDisconnect) {
            return new Exit("exit-error");
        }

        return new Exit("exit-normal");
    }

    public static class CallerDisconnect extends Exception {
        public CallerDisconnect() {}
    }

}

Likewise, it would be good to check for other event like noinput, nomatch, error, etc. depending on the kind of turn you're processing and do something accordingly.

Hello, thanks for your reply. I am not using the timeout in any of the doTurn methods. Besides, I've made some change in the code to consider your last advice about the Connection Disconnect Hangup. BTW, I was always returning new Exit("exit"), didn't do exit-error or exit-normal. ... mmm... in subdialogs, should I return Return("return-error") in case of an error? Thanks — icordoba, Sep 23 '15 at 15:21
There is a default timeout of 60s. So if your interaction (recording) takes more than 60s, you will have a Timeout. — gawi, Sep 24 '15 at 01:14
The "exit-error" vs "exit-normal"... it's just the name of the turn. It has no other impact. — gawi, Sep 24 '15 at 01:16
Yes, in subdialog, you shoud use `return new Return("return", new VariableList())` — gawi, Dec 01 '15 at 00:12

Timeout logs in Rivr Dialogues

1 Answers1