codetheweb / tuyapi

🌧 An easy-to-use API for devices that use Tuya's cloud services. Documentation: https://codetheweb.github.io/tuyapi.
MIT License
2.09k stars 342 forks source link

Error [ERR_UNHANDLED_ERROR]: Unhandled error. #470

Closed brianegge closed 3 years ago

brianegge commented 3 years ago

Describe the bug I am able to get/set using the CLI. When using a server which calls find it results in a timeout error. It fails quickly so isn't actually timing out.

To Reproduce I have the device ID and call tuya.find({timeout: 15}).then(() => { The log shows it finds the device and then it gets the device details and then (immediately) it throws this timeout error.

Expected behavior Expecting it will resolve the device ID to IP.

Debug Output DEBUG= node TuyAPI_Server_v1.js Node.js Version Detected: v10.24.0 TuyAPI Hub Console Log { accept: '/*', 'user-agent': 'Linux UPnP/1.0 SmartThings', host: '192.168.254.6:8083', 'tuyapi-devid': '3664051440f520e9858a', 'tuyapi-localkey': '9257e2426805e8f0', 'tuyapi-command': 'off' } TuyAPI Finding missing IP undefined or ID 3664051440f520e9858a +0ms TuyAPI Received UDP message. +236ms TuyAPI UDP data: +79ms TuyAPI { payload: TuyAPI { ip: '192.168.254.71', TuyAPI gwId: '3664051440f520e9858a', TuyAPI active: 2, TuyAPI ability: 0, TuyAPI mode: 0, TuyAPI encrypt: true, TuyAPI productKey: 'keyj979nf3q3theh', TuyAPI version: '3.3' }, TuyAPI leftover: false, TuyAPI commandByte: 19, TuyAPI sequenceN: 0 } +2ms TuyAPI Found IP 3664051440f520e9858a or ID 192.168.254.71 +23ms TuyAPI Adding IP 192.168.254.71 +1ms TuyAPI SET Payload: +27ms TuyAPI { devId: '3664051440f520e9858a', TuyAPI gwId: '3664051440f520e9858a', TuyAPI uid: '', TuyAPI t: 1621044093, TuyAPI dps: { '1': false } } +3ms TuyAPI Connecting to 192.168.254.71... +114ms TuyAPI Socket connected. +62ms TuyAPI GET Payload: +14ms TuyAPI { gwId: '3664051440f520e9858a', TuyAPI devId: '3664051440f520e9858a', TuyAPI t: '1621044093', TuyAPI dps: {}, TuyAPI uid: '3664051440f520e9858a' } +2ms TuyAPI Received data: 000055aa000000020000000a0000009c00000000a3d73aff2130b6a066e2e6dedc1a8b5dd79d35a46bb047ddd8c900476d1fa42517d0a6071c02f363c503e9f6e2869e473921c2f4fdb405dca1a29be980377cc1069f05537288dd663b92e187a7f3ea81fe5c2aedfd538d66a683aaef34bf410fe417329a7cab32ca4a1f4b347877af6078370038d47ded5c7c408d5f42b32a9a692ae0d093a34c9c6dd469bad73fb2bac5f48edf0000aa55 +71ms TuyAPI Parsed: +11ms TuyAPI { payload: TuyAPI { devId: '3664051440f520e9858a', TuyAPI dps: TuyAPI { '20': false, TuyAPI '21': 'colour', TuyAPI '24': '010E03e803e8', TuyAPI '25': '000e0d00002e03e802cc00000000', TuyAPI '26': 0 } }, TuyAPI leftover: false, TuyAPI commandByte: 10, TuyAPI sequenceN: 2 } +3ms TuyAPI Received DATA packet +22ms TuyAPI Received data: 000055aa00000001000000070000000c00000000a505a9140000aa55 +10ms TuyAPI Parsed: +3ms TuyAPI { payload: false, leftover: false, commandByte: 7, sequenceN: 1 } +3ms TuyAPI Got SET ack. +5ms Error : Error [ERR_UNHANDLED_ERROR]: Unhandled error. ('Timeout waiting for status response from device id: 3664051440f520e9858a')

Desktop (please complete the following information):

Additional context Add any other context about the problem here.

codetheweb commented 3 years ago

Hmm, could you post your script?

brianegge commented 3 years ago

I’m trying to get this script to work: https://github.com/brianegge/TuyaSmartthings/blob/master/TuyAPI_Server_v1.js

It seems quite like the cli. Maybe it’s trying to get the status when it connects but then is also trying to run a set command.

I wish I could flash the firmware, but no luck with these devices: https://www.superbrightleds.com/moreinfo/miniature-and-subminiature-bulbs/g4-led-smart-bi-pin-bulb-rgb-color-changing-hubless-smartphone-compatible/6423/

No one makes a WiFi or zigbee RGB bulb this small. I want to use in it my landscape lighting.

The CLI takes about 0.5 seconds to run on my Mac but up to 30 seconds on my Raspberry Pi 4. I could call the cli from Python, but keeping everything in Node seems to make more sense.

codetheweb commented 3 years ago

The CLI takes about 0.5 seconds to run on my Mac but up to 30 seconds on my Raspberry Pi 4.

That seems odd. Relatively same network config on both?

I could call the cli from Python, but keeping everything in Node seems to make more sense.

👍

It looks like that script is fairly old (using resolveId() instead of find()). Also not clear what version of TuyAPI it's using since the repo rather than a specific version is referenced in package.json. Please do npm uninstall tuyapi && npm i -s tuyapi to add the latest version.

Taking a closer look at your debug log, it looks like the script is trying to set index 1 which doesn't exist on your device. Could you post the CLI commands that you use to set properties?

brianegge commented 3 years ago

I think the raspberry pi is slow because of the node startup - possibly the memory needed or amount of IO. But I can't upgrade past version 10 without installing from source.

Yes, my device uses '20' for the on/off. From the CLI it works fine. I've sync'd to the latest API in both. I've tried changing the resolveId to find, but it seems one just delegates to the other.

DEBUG=* tuya-cli set --id 3664051440f520e9858a  --key 9257e2426805e8f0 --protocol-version 3.3 --dps 20 --set false
  TuyAPI Finding missing IP undefined or ID 3664051440f520e9858a +0ms
  TuyAPI Received UDP message. +3s
  TuyAPI UDP data: +5ms
  TuyAPI {
  TuyAPI   payload: {
  TuyAPI     ip: '192.168.254.71',
  TuyAPI     gwId: '3664051440f520e9858a',
  TuyAPI     active: 2,
  TuyAPI     ability: 0,
  TuyAPI     mode: 0,
  TuyAPI     encrypt: true,
  TuyAPI     productKey: 'keyj979nf3q3theh',
  TuyAPI     version: '3.3'
  TuyAPI   },
  TuyAPI   leftover: false,
  TuyAPI   commandByte: 19,
  TuyAPI   sequenceN: 0
  TuyAPI } +0ms
  TuyAPI Connecting to 192.168.254.71... +4ms
  TuyAPI Socket connected. +5ms
  TuyAPI GET Payload: +0ms
  TuyAPI {
  TuyAPI   gwId: '3664051440f520e9858a',
  TuyAPI   devId: '3664051440f520e9858a',
  TuyAPI   t: '1621385542',
  TuyAPI   dps: {},
  TuyAPI   uid: '3664051440f520e9858a'
  TuyAPI } +0ms
  TuyAPI SET Payload: +2ms
  TuyAPI {
  TuyAPI   devId: '3664051440f520e9858a',
  TuyAPI   gwId: '3664051440f520e9858a',
  TuyAPI   uid: '',
  TuyAPI   t: 1621385542,
  TuyAPI   dps: { '20': false }
  TuyAPI } +0ms
  TuyAPI Received data: 000055aa000000010000000a0000009c00000000a3d73aff2130b6a066e2e6dedc1a8b5dd79d35a46bb047ddd8c900476d1fa42517d0a6071c02f363c503e9f6e2869e473921c2f4fdb405dca1a29be980377cc1069f05537288dd663b92e187a7f3ea81fe5c2aedfd538d66a683aaef34bf410fe417329a7cab32ca4a1f4b347877af6078370038d47ded5c7c408d5f42b32a9a692ae0d093a34c9c6dd469bad73fb2ba5701e6160000aa55 +20ms
  TuyAPI Parsed: +0ms
  TuyAPI {
  TuyAPI   payload: {
  TuyAPI     devId: '3664051440f520e9858a',
  TuyAPI     dps: {
  TuyAPI       '20': false,
  TuyAPI       '21': 'colour',
  TuyAPI       '24': '010E03e803e8',
  TuyAPI       '25': '000e0d00002e03e802cc00000000',
  TuyAPI       '26': 0
  TuyAPI     }
  TuyAPI   },
  TuyAPI   leftover: false,
  TuyAPI   commandByte: 10,
  TuyAPI   sequenceN: 1
  TuyAPI } +0ms
  TuyAPI Received data: 000055aa00000002000000070000000c0000000018cfc5da0000aa55 +27ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 7, sequenceN: 2 } +0ms
  TuyAPI Got SET ack. +0ms
  TuyAPI Received data: 000055aa00000000000000080000006b00000000332e33000000000000002500000001a3d73aff2130b6a066e2e6dedc1a8b5dd79d35a46bb047ddd8c900476d1fa42517d0a6071c02f363c503e9f6e2869e4751dc980c7abb1838014479910a0b9424508e555528bf089b04828892db67a931a5f59c040000aa55 +8ms
  TuyAPI Parsed: +0ms
  TuyAPI {
  TuyAPI   payload: {
  TuyAPI     devId: '3664051440f520e9858a',
  TuyAPI     dps: { '20': false },
  TuyAPI     t: 1621385540
  TuyAPI   },
  TuyAPI   leftover: false,
  TuyAPI   commandByte: 8,
  TuyAPI   sequenceN: 0
  TuyAPI } +0ms
  TuyAPI Disconnect +1ms
Set succeeded.
  TuyAPI Socket closed: 192.168.254.71 +1ms

Tonight, running the server is succeeding on the first call but failing on the second:

   curl -v -H "tuyapi-devid: 3664051440f520e9858a" -H "tuyapi-localkey: 9257e2426805e8f0" -H "tuyapi-command: on" http://192.168.254.176:8083/
...
   curl -v -H "tuyapi-devid: 3664051440f520e9858a" -H "tuyapi-localkey: 9257e2426805e8f0" -H "tuyapi-command: off" http://192.168.254.176:8083/
DEBUG=* node TuyAPI_Server_v1.js
Node.js Version Detected:   v16.1.0
TuyAPI Hub Console Log
{
  host: '192.168.254.176:8083',
  'user-agent': 'curl/7.64.1',
  accept: '*/*',
  'tuyapi-devid': '3664051440f520e9858a',
  'tuyapi-localkey': '9257e2426805e8f0',
  'tuyapi-command': 'on'
}
  TuyAPI Finding missing IP undefined or ID 3664051440f520e9858a +0ms
  TuyAPI Received UDP message. +2s
  TuyAPI UDP data: +1ms
  TuyAPI {
  TuyAPI   payload: {
  TuyAPI     ip: '192.168.254.71',
  TuyAPI     gwId: '3664051440f520e9858a',
  TuyAPI     active: 2,
  TuyAPI     ability: 0,
  TuyAPI     mode: 0,
  TuyAPI     encrypt: true,
  TuyAPI     productKey: 'keyj979nf3q3theh',
  TuyAPI     version: '3.3'
  TuyAPI   },
  TuyAPI   leftover: false,
  TuyAPI   commandByte: 19,
  TuyAPI   sequenceN: 0
  TuyAPI } +0ms
  TuyAPI inserting 3664051440f520e9858a => 192.168.254.71 +0ms
  TuyAPI Adding IP +0ms
Changing state
  TuyAPI SET Payload: +1ms
  TuyAPI {
  TuyAPI   devId: '3664051440f520e9858a',
  TuyAPI   gwId: '3664051440f520e9858a',
  TuyAPI   uid: '',
  TuyAPI   t: 1621385822,
  TuyAPI   dps: { '20': true }
  TuyAPI } +0ms
  TuyAPI Connecting to 192.168.254.71... +1ms
  TuyAPI Socket connected. +10ms
  TuyAPI GET Payload: +0ms
  TuyAPI {
  TuyAPI   gwId: '3664051440f520e9858a',
  TuyAPI   devId: '3664051440f520e9858a',
  TuyAPI   t: '1621385822',
  TuyAPI   dps: {},
  TuyAPI   uid: '3664051440f520e9858a'
  TuyAPI } +0ms
  TuyAPI Received data: 000055aa000000020000000a0000009c00000000a3d73aff2130b6a066e2e6dedc1a8b5dd79d35a46bb047ddd8c900476d1fa42517d0a6071c02f363c503e9f6e2869e473921c2f4fdb405dca1a29be980377cc1069f05537288dd663b92e187a7f3ea81fe5c2aedfd538d66a683aaef34bf410fe417329a7cab32ca4a1f4b347877af6078370038d47ded5c7c408d5f42b32a9a692ae0d093a34c9c6dd469bad73fb2bac5f48edf0000aa55 +19ms
  TuyAPI Parsed: +1ms
  TuyAPI {
  TuyAPI   payload: {
  TuyAPI     devId: '3664051440f520e9858a',
  TuyAPI     dps: {
  TuyAPI       '20': false,
  TuyAPI       '21': 'colour',
  TuyAPI       '24': '010E03e803e8',
  TuyAPI       '25': '000e0d00002e03e802cc00000000',
  TuyAPI       '26': 0
  TuyAPI     }
  TuyAPI   },
  TuyAPI   leftover: false,
  TuyAPI   commandByte: 10,
  TuyAPI   sequenceN: 2
  TuyAPI } +0ms
  TuyAPI Received DATA packet +0ms
  TuyAPI Received data: 000055aa00000001000000070000000c00000000a505a9140000aa55 +35ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 7, sequenceN: 1 } +0ms
  TuyAPI Got SET ack. +0ms
  TuyAPI Received data: 000055aa00000000000000080000006b00000000332e33000000000000002600000001a3d73aff2130b6a066e2e6dedc1a8b5dd79d35a46bb047ddd8c900476d1fa42510bd94fece2c9e09715152ba599526bc5a44076f5a620ed301de1b479c4a1e88dd21ebe93525c5fdd8da7294e0c1a3270bad00fc0000aa55 +7ms
  TuyAPI Parsed: +0ms
  TuyAPI {
  TuyAPI   payload: { devId: '3664051440f520e9858a', dps: { '20': true }, t: 1621385820 },
  TuyAPI   leftover: false,
  TuyAPI   commandByte: 8,
  TuyAPI   sequenceN: 0
  TuyAPI } +0ms
  TuyAPI Received DP_REFRESH packet. +0ms
Result of setting status to true: [object Object]
Status (on) sent to SmartThings.
  TuyAPI Pinging 192.168.254.71 +10s
  TuyAPI Received data: 000055aa00000000000000090000000c00000000b051ab030000aa55 +258ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 9, sequenceN: 0 } +0ms
  TuyAPI Pong from 192.168.254.71 +0ms
  TuyAPI Pinging 192.168.254.71 +10s
  TuyAPI Received data: 000055aa00000000000000090000000c00000000b051ab030000aa55 +82ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 9, sequenceN: 0 } +0ms
  TuyAPI Pong from 192.168.254.71 +0ms
{
  host: '192.168.254.176:8083',
  'user-agent': 'curl/7.64.1',
  accept: '*/*',
  'tuyapi-devid': '3664051440f520e9858a',
  'tuyapi-localkey': '9257e2426805e8f0',
  'tuyapi-command': 'off'
}
  TuyAPI Finding missing IP undefined or ID 3664051440f520e9858a +4s
  TuyAPI Pinging 192.168.254.71 +6s
  TuyAPI Received data: 000055aa00000000000000090000000c00000000b051ab030000aa55 +245ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 9, sequenceN: 0 } +0ms
  TuyAPI Pong from 192.168.254.71 +1ms
Error : Error: find() timed out. Is the device powered on and the ID or IP correct?
  TuyAPI Pinging 192.168.254.71 +10s
  TuyAPI Received data: 000055aa00000000000000090000000c00000000b051ab030000aa55 +61ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 9, sequenceN: 0 } +0ms
  TuyAPI Pong from 192.168.254.71 +0ms
  TuyAPI Pinging 192.168.254.71 +10s

It seems as though the Tuya is still running after the request, with ping/pong occuring in the log file

  TuyAPI Received DP_REFRESH packet. +1ms
Result of setting status to false: [object Object]
Status (off) sent to SmartThings.
  TuyAPI Pinging 192.168.254.71 +10s
  TuyAPI Received data: 000055aa00000000000000090000000c00000000b051ab030000aa55 +189ms
  TuyAPI Parsed: +0ms
  TuyAPI { payload: false, leftover: false, commandByte: 9, sequenceN: 0 } +0ms
  TuyAPI Pong from 192.168.254.71 +0ms
  TuyAPI Pinging 192.168.254.71 +10s
  TuyAPI Received data: 000055aa00000000000000090000000c00000000b051ab030000aa55 +333ms
  TuyAPI Parsed: +1ms
  TuyAPI { payload: false, leftover: false, commandByte: 9, sequenceN: 0 } +0ms
  TuyAPI Pong from 192.168.254.71 +0ms

The next request is doomed as it seems the first TCP connection is still open but abandoned. I don't know Node well enough to understand how the object can live on. It would be of course useful for the server to keep the object in memory once it's resolved it's IP address, but calling it a second time seems to create a second object.

Maybe the server needs to cache the TuyaDevice in the onRequest method, and the CLI works because it's not cached?

codetheweb commented 3 years ago

I think the raspberry pi is slow because of the node startup - possibly the memory needed or amount of IO. But I can't upgrade past version 10 without installing from source.

Sure, but 30s seems excessive. Doesn't really matter if you're not using I guess. 🤷

The next request is doomed as it seems the first TCP connection is still open but abandoned. I don't know Node well enough to understand how the object can live on. It would be of course useful for the server to keep the object in memory once it's resolved it's IP address, but calling it a second time seems to create a second object. Maybe the server needs to cache the TuyaDevice in the onRequest method, and the CLI works because it's not cached?

You got it. 👍 Node won't garbage collect it because of the setInterval() usage internally in TuyAPI. One solution would be to call tuya.disconnect() at the end, but as you mentioned the better option is to make the TuyAPI instance global relative to the request handler. I recomend doing something like this:

let tuya;
...
server.listen(hubPort, async error => {
  if (error) {
    throw error;
  }

  tuya = new TuyaDevice({
    id: deviceID,
    key: localKey
  });

  await tuya.find();
  await tuya.connect();
}));

and then remove the init call in onRequest().

brianegge commented 3 years ago

Thank you. I was able to get things working at least as well as the cli anyway. Subsequent calls to find() don't seem to look up the cached connection - that's an optimization I can make.

Next step is getting the RGB get/set functions to work. I understand the encoding, and just need to convert the SmartThings values to the hex values and call set.

codetheweb commented 3 years ago

Glad it's working. 👍