csuermann / virtual-smart-home

Virtual Smart Home Skill for Amazon Alexa and Node-RED
27 stars 18 forks source link

Smart Devices do not respond withing Alexa App #11

Closed FrankGiesecke closed 1 year ago

FrankGiesecke commented 1 year ago

I'm currently using the PRO Plan to manage my smart devices.

Now, I've tried to setup the backend within my AWS Account. Everthing seems to work.

But: When I move a device from your instance to mine, the device didn't resend in the Alexa app. It shows up correctly, but when sending a command (using voice or the Alexa app), I'll get the message, that the device is not responding or the server is not ready.

Can I find some logs in AWS to check, if the requests are sent? Where can I find the devices in AWS?

csuermann commented 1 year ago

Hi @FrankGiesecke,

You should be able to find logs in AWS Cloudwatch and devices under AWS IoT Core.

FrankGiesecke commented 1 year ago

Thanks for your fast reply.

So I found some errors in the logs:

/aws/lambda/virtual-smart-home-dev-backchannel

INIT_START Runtime Version: nodejs:16.v12   Runtime Version ARN: arn:aws:lambda:eu-west-1::runtime:734d712d91ebc245bd01c52ae85b4025a7885efd1b8c87c0ce49f3e47d2116a4
--
START RequestId: b5cd5a59-1033-4050-8bce-ec3f55f57934 Version: $LATEST
2023-03-08T14:41:20.335Z    b5cd5a59-1033-4050-8bce-ec3f55f57934    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: b5cd5a59-1033-4050-8bce-ec3f55f57934
REPORT RequestId: b5cd5a59-1033-4050-8bce-ec3f55f57934  Duration: 1218.67 ms    Billed Duration: 1219 ms    Memory Size: 256 MB Max Memory Used: 223 MB Init Duration: 1252.45 ms
START RequestId: f6cf5e03-5ac3-4f4c-8cf7-2aaf31023cda Version: $LATEST
2023-03-08T14:41:30.023Z    f6cf5e03-5ac3-4f4c-8cf7-2aaf31023cda    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: f6cf5e03-5ac3-4f4c-8cf7-2aaf31023cda
REPORT RequestId: f6cf5e03-5ac3-4f4c-8cf7-2aaf31023cda  Duration: 130.20 ms Billed Duration: 131 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: ed50a5c9-1d4d-461e-b6da-5ac6090df280 Version: $LATEST
2023-03-08T14:42:27.687Z    ed50a5c9-1d4d-461e-b6da-5ac6090df280    ERROR   ✖ pushAsyncChangeReportToAlexa FAILED! malformed auth token
END RequestId: ed50a5c9-1d4d-461e-b6da-5ac6090df280
REPORT RequestId: ed50a5c9-1d4d-461e-b6da-5ac6090df280  Duration: 732.19 ms Billed Duration: 733 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 18bc23ea-a4dd-44de-b078-afffa3d863ed Version: $LATEST
2023-03-08T14:42:47.516Z    18bc23ea-a4dd-44de-b078-afffa3d863ed    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: 18bc23ea-a4dd-44de-b078-afffa3d863ed
REPORT RequestId: 18bc23ea-a4dd-44de-b078-afffa3d863ed  Duration: 587.80 ms Billed Duration: 588 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: a6469128-1c9d-4475-9862-9ddc97b49c69 Version: $LATEST
2023-03-08T14:42:52.406Z    a6469128-1c9d-4475-9862-9ddc97b49c69    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: a6469128-1c9d-4475-9862-9ddc97b49c69
REPORT RequestId: a6469128-1c9d-4475-9862-9ddc97b49c69  Duration: 123.50 ms Billed Duration: 124 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 4fa1dc39-1565-4ad5-8b01-3f0ddedb109a Version: $LATEST
END RequestId: 4fa1dc39-1565-4ad5-8b01-3f0ddedb109a
REPORT RequestId: 4fa1dc39-1565-4ad5-8b01-3f0ddedb109a  Duration: 239.38 ms Billed Duration: 240 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c Version: $LATEST
2023-03-08T14:46:18.082Z    374f9f11-f3d8-4287-bae1-d772a8432e9c    ERROR   Invoke Error    {     "errorType": "ConditionalCheckFailedException",     "errorMessage": "The conditional request failed",     "code": "ConditionalCheckFailedException",     "message": "The conditional request failed",     "time": "2023-03-08T14:46:18.080Z",     "requestId": "VUOJUPN9U751C4D1RMV24V2OUNVV4KQNSO5AEMVJF66Q9ASUAAJG",     "statusCode": 400,     "retryable": false,     "retryDelay": 23.557435136026584,     "stack": [         "ConditionalCheckFailedException: The conditional request failed",         "    at constructor.apply (/var/task/webpack:/node_modules/aws-sdk/lib/protocol/json.js:52:27)",         "    at constructor.callListeners (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:106:20)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:78:10)",         "    at constructor.emit [as emitEvent] (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:686:14)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:22:10)",         "    at runTo (/var/task/webpack:/node_modules/aws-sdk/lib/state_machine.js:14:12)",         "    at done (/var/task/webpack:/node_modules/aws-sdk/lib/state_machine.js:26:10)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:38:9)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:688:12)",         "    at constructor.callListeners (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:116:18)"     ] }
END RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c
REPORT RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c  Duration: 85.90 ms  Billed Duration: 86 ms  Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 0ff354df-73b8-48ba-99f4-d37589359f3f Version: $LATEST
2023-03-08T14:46:29.559Z    0ff354df-73b8-48ba-99f4-d37589359f3f    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: 0ff354df-73b8-48ba-99f4-d37589359f3f
REPORT RequestId: 0ff354df-73b8-48ba-99f4-d37589359f3f  Duration: 84.81 ms  Billed Duration: 85 ms  Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 8eaa9a3f-2553-4c23-a667-08f16178e3cb Version: $LATEST
2023-03-08T14:46:34.756Z    8eaa9a3f-2553-4c23-a667-08f16178e3cb    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: 8eaa9a3f-2553-4c23-a667-08f16178e3cb
REPORT RequestId: 8eaa9a3f-2553-4c23-a667-08f16178e3cb  Duration: 109.44 ms Billed Duration: 110 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 530dab63-ac2d-4505-b8da-e677d33919bb Version: $LATEST
2023-03-08T14:46:40.957Z    530dab63-ac2d-4505-b8da-e677d33919bb    ERROR   ✖ pushAsyncResponseToAlexa FAILED! malformed auth token
END RequestId: 530dab63-ac2d-4505-b8da-e677d33919bb
REPORT RequestId: 530dab63-ac2d-4505-b8da-e677d33919bb  Duration: 98.22 ms  Billed Duration: 99 ms  Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c Version: $LATEST
2023-03-08T14:47:14.363Z    374f9f11-f3d8-4287-bae1-d772a8432e9c    ERROR   Invoke Error    {     "errorType": "ConditionalCheckFailedException",     "errorMessage": "The conditional request failed",     "code": "ConditionalCheckFailedException",     "message": "The conditional request failed",     "time": "2023-03-08T14:47:14.362Z",     "requestId": "364RQDEUFQJ9FQQ301VEHFDGBBVV4KQNSO5AEMVJF66Q9ASUAAJG",     "statusCode": 400,     "retryable": false,     "retryDelay": 48.66881906694015,     "stack": [         "ConditionalCheckFailedException: The conditional request failed",         "    at constructor.apply (/var/task/webpack:/node_modules/aws-sdk/lib/protocol/json.js:52:27)",         "    at constructor.callListeners (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:106:20)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:78:10)",         "    at constructor.emit [as emitEvent] (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:686:14)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:22:10)",         "    at runTo (/var/task/webpack:/node_modules/aws-sdk/lib/state_machine.js:14:12)",         "    at done (/var/task/webpack:/node_modules/aws-sdk/lib/state_machine.js:26:10)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:38:9)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:688:12)",         "    at constructor.callListeners (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:116:18)"     ] }
END RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c
REPORT RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c  Duration: 93.94 ms  Billed Duration: 94 ms  Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 09e466b6-35ef-4440-98ac-ee1d03a9fbfb Version: $LATEST
END RequestId: 09e466b6-35ef-4440-98ac-ee1d03a9fbfb
REPORT RequestId: 09e466b6-35ef-4440-98ac-ee1d03a9fbfb  Duration: 180.67 ms Billed Duration: 181 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866 Version: $LATEST
2023-03-08T14:47:17.615Z    412b64a0-a5f2-48a2-9c36-83bdf3d77866    ERROR   Invoke Error    {     "errorType": "InvalidArgumentError",     "errorMessage": "malformed auth token",     "name": "InvalidArgumentError",     "stack": [         "InvalidArgumentError: malformed auth token",         "    at decodeJwt (/var/task/webpack:/node_modules/@gomomento/sdk/dist/src/utils/jwt.js:12:15)",         "    at new t.SimpleCacheClient (/var/task/webpack:/node_modules/@gomomento/sdk/dist/src/simple-cache-client.js:31:34)",         "    at /var/task/webpack:/cache.ts:13:12",         "    at Generator.next (<anonymous>)",         "    at /var/task/handler.js:7:52271",         "    at new Promise (<anonymous>)",         "    at s (/var/task/handler.js:7:52016)",         "    at getMomentoClient (/var/task/handler.js:7:52484)",         "    at Object.<anonymous> (/var/task/webpack:/cache.ts:82:25)",         "    at Generator.next (<anonymous>)"     ] }
END RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866
REPORT RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866  Duration: 99.60 ms  Billed Duration: 100 ms Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866 Version: $LATEST
2023-03-08T14:48:10.855Z    412b64a0-a5f2-48a2-9c36-83bdf3d77866    ERROR   Invoke Error    {     "errorType": "InvalidArgumentError",     "errorMessage": "malformed auth token",     "name": "InvalidArgumentError",     "stack": [         "InvalidArgumentError: malformed auth token",         "    at decodeJwt (/var/task/webpack:/node_modules/@gomomento/sdk/dist/src/utils/jwt.js:12:15)",         "    at new t.SimpleCacheClient (/var/task/webpack:/node_modules/@gomomento/sdk/dist/src/simple-cache-client.js:31:34)",         "    at /var/task/webpack:/cache.ts:13:12",         "    at Generator.next (<anonymous>)",         "    at /var/task/handler.js:7:52271",         "    at new Promise (<anonymous>)",         "    at s (/var/task/handler.js:7:52016)",         "    at getMomentoClient (/var/task/handler.js:7:52484)",         "    at Object.<anonymous> (/var/task/webpack:/cache.ts:82:25)",         "    at Generator.next (<anonymous>)"     ] }
END RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866
REPORT RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866  Duration: 75.55 ms  Billed Duration: 76 ms  Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c Version: $LATEST
2023-03-08T14:49:11.584Z    374f9f11-f3d8-4287-bae1-d772a8432e9c    ERROR   Invoke Error    {     "errorType": "ConditionalCheckFailedException",     "errorMessage": "The conditional request failed",     "code": "ConditionalCheckFailedException",     "message": "The conditional request failed",     "time": "2023-03-08T14:49:11.583Z",     "requestId": "B1CSU23UQ4FST5RRFSEFOJTNNBVV4KQNSO5AEMVJF66Q9ASUAAJG",     "statusCode": 400,     "retryable": false,     "retryDelay": 15.073985972787884,     "stack": [         "ConditionalCheckFailedException: The conditional request failed",         "    at constructor.apply (/var/task/webpack:/node_modules/aws-sdk/lib/protocol/json.js:52:27)",         "    at constructor.callListeners (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:106:20)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:78:10)",         "    at constructor.emit [as emitEvent] (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:686:14)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:22:10)",         "    at runTo (/var/task/webpack:/node_modules/aws-sdk/lib/state_machine.js:14:12)",         "    at done (/var/task/webpack:/node_modules/aws-sdk/lib/state_machine.js:26:10)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:38:9)",         "    at constructor.call (/var/task/webpack:/node_modules/aws-sdk/lib/request.js:688:12)",         "    at constructor.callListeners (/var/task/webpack:/node_modules/aws-sdk/lib/sequential_executor.js:116:18)"     ] }
END RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c
REPORT RequestId: 374f9f11-f3d8-4287-bae1-d772a8432e9c  Duration: 67.13 ms  Billed Duration: 68 ms  Memory Size: 256 MB Max Memory Used: 223 MB
START RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866 Version: $LATEST
2023-03-08T14:50:00.296Z    412b64a0-a5f2-48a2-9c36-83bdf3d77866    ERROR   Invoke Error    {     "errorType": "InvalidArgumentError",     "errorMessage": "malformed auth token",     "name": "InvalidArgumentError",     "stack": [         "InvalidArgumentError: malformed auth token",         "    at decodeJwt (/var/task/webpack:/node_modules/@gomomento/sdk/dist/src/utils/jwt.js:12:15)",         "    at new t.SimpleCacheClient (/var/task/webpack:/node_modules/@gomomento/sdk/dist/src/simple-cache-client.js:31:34)",         "    at /var/task/webpack:/cache.ts:13:12",         "    at Generator.next (<anonymous>)",         "    at /var/task/handler.js:7:52271",         "    at new Promise (<anonymous>)",         "    at s (/var/task/handler.js:7:52016)",         "    at getMomentoClient (/var/task/handler.js:7:52484)",         "    at Object.<anonymous> (/var/task/webpack:/cache.ts:82:25)",         "    at Generator.next (<anonymous>)"     ] }
END RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866
REPORT RequestId: 412b64a0-a5f2-48a2-9c36-83bdf3d77866  Duration: 88.65 ms  Billed Duration: 89 ms  Memory Size: 256 MB Max Memory Used: 223 MB
csuermann commented 1 year ago

Hi @FrankGiesecke,

Apologies for the delay in getting back to you. Although VSH is open source, it is not optimized for easily deploying it to people's own AWS accounts and I actually don't think it's worth the hassle.

However, looking through your logs, my hunch is that the caching service Momento is not configured on your end. Unless you want to fork VSH and remove the cache from the code, you'd need to replicate my setup and also obtain a token from Momento and set it as MOMENTO_TOKEN environment variable.

FrankGiesecke commented 1 year ago

Hi @csuermann,

thanks for your reply. I'll create a Momento account and try again. There was no hint to need Momento in your guide.

Although VSH is open source, it is not optimized for easily deploying it to people's own AWS accounts and I actually don't think it's worth the hassle.

I know. But hosting in my own AWS account has two reasons:

  1. I want to learn more about the AWS services.
  2. I've lost some smarthome features in the past, as the open source cloud services went down due to missing support. So I was very happy to see, that this project gives a guide how to run the necessary services.
FrankGiesecke commented 1 year ago

Cool, creating an momento account and using the token did the trick. I'm now able to control devices which are connected to my instance.

But I'm facing the next "problem". If a device is connected to your instance (using the PRO plan), it can receive data and show up the current state within the alexa app. But if the device is connected to my instance, it doesn't. It seems that the "private instance" is acting like the free one. Is there a way to change this?

csuermann commented 1 year ago

Glad to hear configuring Momento actually resolved your issue. Would be cool if you could submit a PR to improve the docs accordingly.

To bypass the "free" plan limitation, you can promote your own account by adding "plan": "pro" to the "TOKEN" record in your DynamoDB.

https://eu-west-1.console.aws.amazon.com/dynamodbv2/home?region=eu-west-1#edit-item?table=VSH&itemMode=2&pk=USER%23amzn1.account.AFXXXXXXXXXX&sk=TOKEN&route=ROUTE_ITEM_EXPLORER

FrankGiesecke commented 1 year ago

Would be cool if you could submit a PR to improve the docs accordingly.

Sure, here it is 😊 ... https://github.com/csuermann/virtual-smart-home/pull/12

FrankGiesecke commented 1 year ago

The next strange behavior:

Controlling a device connected to my instance within the Alexa app works fine. The device changes the state, color and so on. The app also shows the right state (power state, color, temperature, ...).

But controlling the device by voice failed. The Echo lights up for some time. but nothing happens. I can't see any error in the app.

FrankGiesecke commented 1 year ago

I can see the following logs...

/aws/lambda/virtual-smart-home-dev-backendApi

:aws:lambda:virtual-smart-home-dev-backendApi

/aws/lambda/virtual-smart-home-dev-backchannel

:aws:lambda:virtual-smart-home-dev-backchannel
FrankGiesecke commented 1 year ago

And this is, what I see in NodeRED

device node connection node
FrankGiesecke commented 1 year ago

Strange things happen: NodeRED shows me my instance as PRO. I didn't change anythig 🤔

csuermann commented 1 year ago

Your Node-RED VSH package probably picked up the PRO plan change you made in DynamoDB upon restart?!

FrankGiesecke commented 1 year ago

Your Node-RED VSH package probably picked up the PRO plan change you made in DynamoDB upon restart?!

You are right. While checking the logs I can see a restart entry last night.