alexa / alexa-skills-kit-sdk-for-nodejs

The Alexa Skills Kit SDK for Node.js helps you get a skill up and running quickly, letting you focus on skill logic instead of boilerplate code.
Apache License 2.0
3.12k stars 736 forks source link

The SDK sometimes fails to write the attributes to DynamoDB #164

Closed coltonw closed 7 years ago

coltonw commented 7 years ago

Update attributes, emit :tell or something and the dynamodb table seems to update (for me) less than half the time.

I believe the problem is related to this stackoverflow issue. In response.js, the context.succeed() call is done before waiting for the dynamodb write to actually complete, so the Lambda exits without actually doing the asynchronous write.

coltonw commented 7 years ago

Don't know if this makes a difference, but I was NOT passing in a callback to Alexa.handlers. Seems to work a bit better when using the callback. Even so, it is possibly working better by sheer luck (since this may be a timing issue). It looks like PR #127 introduced this problem.

GomuGomuMan commented 7 years ago

I also have this problem, but cannot produce a specific test case right now.

t2048 commented 7 years ago

Sorry for the formatting, my first feedback on github -

Pretty sure this change in logic - https://github.com/alexa/alexa-skills-kit-sdk-for-nodejs/pull/127 - has created a bug where the lambda returns before writes to DynamoDB have finished. I added logging to the response.js ':saveState' code as follows:

            console.log('saving state');
            attributesHelper.set(this.handler.dynamoDBTableName, userId, this.attributes, (err) => {
                console.log('state saved');

Look at execution in Cloudwatch and you can see the 'state saved' message often is not logged until after the requestId has logged its 'END' event.

2017-08-30T08:46:14.782Z adf4560c-8d5f-11e7-8824-411bdd375215 saving state END RequestId: adf4560c-8d5f-11e7-8824-411bdd375215 START RequestId: b4a04085-8d5f-11e7-8d9c-dfd1ecc96a8e Version: $LATEST 2017-08-30T08:46:25.005Z adf4560c-8d5f-11e7-8824-411bdd375215 state saved

After restoring the previous behavior my skill works as expected now:

for :responseReady: if (this.handler.dynamoDBTableName) { return this.emit(':saveState'); //added the 'return' back }

for :saveState:

        if (this.handler.saveBeforeResponse || forceSave || this.handler.response.response.shouldEndSession) {
            //console.log('saving state');
            attributesHelper.set(this.handler.dynamoDBTableName, userId, this.attributes, (err) => {
                //console.log('state saved');
                if(err) {
                    return this.emit(':saveStateError', err);
                }
                //added this back
                if (typeof this.callback === 'undefined') {
                    this.context.succeed(this.handler.response);
                } else {
                    this.callback(null, this.handler.response);
                }

            });
        }
        else
        {
            //added this back
            if (typeof this.callback === 'undefined') {
                this.context.succeed(this.handler.response);
            } else {
                this.callback(null, this.handler.response);
            }
        }
tgies commented 7 years ago

It figures, because now we are emitting :saveState and then immediately calling context.succeed(), causing the Lambda to suspend or terminate and abandoning the :saveState on the event loop.

Previously, context.succeed() would get called either within :responseReady or :saveState handler (the return was making it dump out before :responseReady handler got to call context.succeed()).

I'm really not sure how to make :saveState work as an event, safely, and also preserve the documented behavior that #127 had in mind (i.e. that :saveState by itself does not call context.succeed()). If you can just this.emit(':saveState') wherever as a non-request-ending operation, there's no good way to wait for that event handler to finish before you do whatever else you do that might result in the request terminating before :saveState has succeeded. Am I wrong?

(In my case this was causing weird behavior where the event would eventually get handled on the next invocation of the Lambda, so my attributes in DynamoDB were getting set, but lagging one invocation behind when I thought I set them. I was extremely confused before I remembered the "freezing" post-request behavior of Lambda which is allowing the :saveState left on the event loop to get dutifully handled on a subsequent invocation of the same container...!)

ghost commented 7 years ago

@tgies

Adding the lambda callback parameter to the Alexa handler will resolve this issue. This will cause lambda to only exit/terminate once the event loop is empty.

const Alexa = require('alexa-sdk');

exports.handler = function(event, context, callback){
    const alexa = Alexa.handler(event, context, callback);
};

Apart from that, It seems that a save state function with a promise (so a developer can control what happens onComplete and onError) could be useful here. That way you can guarantee the state is saved before emitting the response:

someSaveStateFunc()
.then(() => {
   //build response
   this.emit(':responseReady');
})
.error((err) => {
   // error saving state
});
t2048 commented 7 years ago

Here's my recommendation:

https://github.com/alexa/alexa-skills-kit-sdk-for-nodejs/pull/127 should just be reverted. Restore :saveState to it's previous behavior.

Any solution to this issue that does not restore the previous behavior of :saveState - even if it's a one line change like adding the callback parameter to Alexa.handler - is going to force everyone out there who has already written code (including all of the alexa-cookbook examples btw) to "fix" something that they don't even know is broken (unless they are reading this github page). All they will know after updating their alexa-sdk package is that something isn't working right.

The idea of a saveState function that returns a promise or a callback could be useful - but consider the use case here. saveState is basic and mostly automatic functionality for loading and saving session.attributes on a per-user basis. It is intended to, and in most cases does, just work correctly on its own without any direct call from the skill code (always saving when shouldEndSession is true, for example).

Saving of session.attributes should, in every use case I can imagine, be done once (if at all) just prior to the completion of the lambda, and this is reflected in the original design. What if saving fails, you ask? Wouldn't we want to know that? Yes of course, but do your users need to know? There is already logging in saveState to emit saveStateError which logs the error to the console and, if you're a developer, you will see. But are you really going to change the response that you speak to your users? "Sorry, I couldn't save your session attributes to the database, please try again" ?

Leave it to advanced users to build out their own saveState functionality independently from the convenience routine inside alexa-sdk if they want more control over saving and loading to and from the DynamoDB table. This is a much cleaner solution than what we have right now, which introduced new behavior to the existing saveState method which has silently broken all of the existing code, including the alexa-cookbook examples.

The saveState inside alexa-sdk should remain a mostly automatic/hidden method (coming from C++ I wonder "why isn't this marked protected: or private:?") which shouldn't be called directly at all. The recommended way of ensuring session.attributes gets saved prior to lambda completion (in cases where it isn't already automatically saved) should be as follows:

session.handler.saveBeforeResponse = true; session.emit(':responseReady');

Other than that I don't have much to say about it ;)

ghost commented 7 years ago

I've reverted #127 and released 1.0.14 to resolve #164 and patch the silent write failures introduced with the change.