Enable logging for Jovo core

v3

#1

I’m trying to debug a skill that stops working after a few hours. It’s a self-hosted skill on a node server and when the skill becomes unresponsive, i don’t get any errors. So all i can do is restart the server and the skill works again.

We’re running multiple skills on the same server on different ports, with an additional express server that dispatches different endpoints to the respective skill.

This works fine - until it doesn’t.

In the “error” case, the endpoint is called, where i call the “handle” function of the app instance, but from there it doesn’t reach any other method of the skill, and i have no indication whatsoever what the cause might be.

In the handle function in "jovo-core/dist/src/core/BaseApp.js i see several log outputs like:

Log_1.Log.setRequestContext(host);
Log_1.Log.verbose(Log_1.Log.header('Start request ', 'framework'));
Log_1.Log.yellow().verbose(`this.$type: ${JSON.stringify(handleRequest.jovo.$type)} `);
Log_1.Log.yellow().verbose(`this.$session.$data : JSON.stringify(handleRequest.jovo.$session.$data)}`);

How do i enable those?


#2

You can change the log level using environment variables. Learn more here: https://v3.jovo.tech/docs/data/logging#log-levels

process.env.JOVO_LOG_LEVEL='VERBOSE';

#3

Thanks for the response, but that didn’t generate any additional output.

I added “logging: true” to the App options and got a little information:

2022-07-12 07:36:18:    "request": {
2022-07-12 07:36:18:       "type": "SessionEndedRequest",
2022-07-12 07:36:18:       "requestId": "amzn1.echo-api.request.50fde119-cbef-485f-93a8-ced9b0037c6a",
2022-07-12 07:36:18:       "timestamp": "2022-07-12T05:36:18Z",
2022-07-12 07:36:18:       "locale": "de-DE",
2022-07-12 07:36:18:       "reason": "ERROR",
2022-07-12 07:36:18:       "error": {
2022-07-12 07:36:18:          "type": "INVALID_RESPONSE",
2022-07-12 07:36:18:          "message": "An exception occurred while dispatching the request to the skill."
2022-07-12 07:36:18:       }
2022-07-12 07:36:18:    }

Is there any way to get a call stack for this exception?

The strange thing is that after calling handle() no code of the actual skill gets called / executed.


#4

It just occured to me that i don’t have a SessionEndedRequest handler. Is there a default handler for this in Jovo? And if not, how should i handle it?


#5

You can use END for this


#6

It seems the SessionEndedRequest with the embedded error is just a consequence, but not the real issue. So adding the intent handler didn’t change anything.

I still have no idea what’s going on or how to debug this. Any ideas?


#7

After many more hours of debugging (= looking through megabytes of logfiles), i’m starting to believe that Jovo might be at least somewhat responsible. My findings so far:

  • the issue is most likely related to custom tasks

  • (a custom task is delivered to the skill through a “normal” launch request with additional parameters)

  • 99.9% of the time the custom task handling works fine

  • in the error case, the skills response to the request is sent, and about 10-11 seconds later i get a request with already mentioned error:
    “An exception occurred while dispatching the request to the skill”

I couldn’t find out yet what this error message actually means.

In this case neither the END, ON_ERROR or UNHANDLED intent is called and therefore it remains unhandled.

From that moment on, the skills stops working. This means that it does not respond to any incoming request.

It seems as if the Jovo core is in some kind of error state internally and therefore does not dispatch any incoming intents. The only way out is a restart.

(Side question): Can i access the raw response that’s sent back to Amazon somehow?


#8

Because of the asynchronous handling, i made a small mistake in the interpretation of my log files:

Correction:
In the error case, the incoming Custom Task is dispatched to the skill and handled correctly by the skill.

But the call to handle() does not return in this case.

From this moment on, all following requests fail.

The conclusion is still that the Jovo core is in some kind of error state internally, and i need some advice about how to debug this further.