plasticrake / tplink-smarthome-api

TP-Link Smarthome WiFi API
MIT License
1.02k stars 142 forks source link

UnhandledPromiseRejectionWarning #71

Closed cepera63 closed 2 years ago

cepera63 commented 5 years ago
UnhandledPromiseRejectionWarning: Error: TCP Timeout
at Timeout.setTimeout [as _onTimeout] (/.../node_modules/tplink-smarthome-api/lib/client.js:228:20)
    at listOnTimeout (internal/timers.js:535:17)
    at processTimers (internal/timers.js:479:7)

script as easy as

client.getDevice({host: '192.168.1.126'}).then((device)=>{
 device.setPowerState(true);
 console.log( d.toLocaleTimeString() + ' power on!');
 timeoutObj = setTimeout(pOff, 30*1000); // 30s -> off
});
spddl commented 5 years ago

try to expand the timeout time

const { Client } = require('tplink-smarthome-api')
const client = new Client({ defaultSendOptions: { timeout: 30000 } })
cepera63 commented 5 years ago

I will, but same would happen if device is just turned off or just incorrect IP. Seems need to handle exception.

 [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
DavidBurg commented 5 years ago

I ran into an unhandled promise rejection, too. It is coming from the Device.send method, which is indirectly being called from the Device.startPolling method. The problem is that the try/catch code in Device.startPolling doesn't really work, as mentioned in this MDN page, which states:

If you used the try/catch block here, you might still get unhandled errors in the myFetch() function when it's called.

I also noticed that Device.startPolling tries to emit a 'polling-error' event, which isn't mentioned in the documentation. The event isn't emitted, though, due to the problems with the try/catch code.

The solution is for Device.startPolling to be:

    const fn = () => {
        this.getInfo().catch((err) => {
        this.log.debug('[%s] device.startPolling(): getInfo(): error:', this.alias, err);
        /**
         * @event Device#polling-error
         * @property {Error} error
         */
        this.emit('polling-error', err);
        })
    };
    this.pollingTimer = setInterval(fn, interval);
    fn();
    return this;
    }
DavidBurg commented 5 years ago

I ran into an unhandled promise rejection, too. It is coming from the Device.send method, which is indirectly being called from the Device.startPolling method. The problem is that the try/catch code in Device.startPolling doesn't really work, as mentioned in this MDN page, which states:

If you used the try/catch block here, you might still get unhandled errors in the myFetch() function when it's called.

I also noticed that Device.startPolling tries to emit a 'polling-error' event, which isn't mentioned in the documentation. The event isn't emitted, though, due to the problems with the try/catch code.

The solution is for Device.startPolling to be:

    const fn = () => {
        this.getInfo().catch((err) => {
        this.log.debug('[%s] device.startPolling(): getInfo(): error:', this.alias, err);
        /**
         * @event Device#polling-error
         * @property {Error} error
         */
        this.emit('polling-error', err);
        })
    };
    this.pollingTimer = setInterval(fn, interval);
    fn();
    return this;
    }
DavidBurg commented 5 years ago

BTW... I tried to reproduce cepera63's result. The example code didn't run due to missing dependencies. But, I think cepera63's problem should be solved in the user's code by attaching a .catch, like this:

client.getDevice({host: '192.168.1.126'}).then((device)=>{
    device.setPowerState(true);
    console.log( new Date().toLocaleTimeString() + ' power on!');
}).catch((e) => {console.log('caught getDevice error', e);});

This will catch and handle the otherwise uncaught error in the user's code.

However, since Device.startPolling doesn't return a promise, the uncaught error cannot be handled in the user's code. So, Device.startPolling should be fixed.

plasticrake commented 5 years ago

@DavidBurg I don't have time to look into this for a few weeks, but there is a test case for polling-error so it's odd if its not working in your testing.

DavidBurg commented 5 years ago

@plasticrake Thanks for the quick response. There's no hurry, I know the solution. I'll send you a testcase this afternoon.

DavidBurg commented 5 years ago

@plasticrake Here's the testcase. I ran it twice, once with no args, and once like "node test.js pass". In each case, after it discovered my 3 plugs, I disabled the WiFi on my laptop.

'use strict';

// Constants

var pass = false;
process.argv.forEach((val, index) => {
    if (val === "pass") pass = true;
});
console.log('pass =', pass);

const { Client } = require('tplink-smarthome-api');
const client = new Client();

const dateString_options = {weekday: 'short', hour: 'numeric', minute: 'numeric' };

var logEvent = function (eventName, device, state) {
    console.log(`${(new Date()).toLocaleDateString("en-US", dateString_options)} ${eventName} ${device.model} "${device.name}" ${device.host}:${device.port}`);
};

// Client events `device-*` also have `bulb-*` and `plug-*` counterparts.
// Use those if you want only events for those types and not all devices.
client.on('device-new', (device) => {
    logEvent('device-new', device);

    if (pass) {
    //----\/---- workaround startPolling() problem ----\/---- 
    device.myStartPolling = function(interval) {
        const fn = () => {
        this.getInfo().catch((err) => {
            this.log.debug('[%s] device.myStartPolling(): getInfo(): error:', this.alias, err);
            /**
             * @event Device#polling-error
             * @property {Error} error
             */
            this.emit('polling-error', err);
        })
            };
        this.pollingTimer = setInterval(fn, interval);
        fn();
        return this;
    }
    device.myStartPolling(5000);
    //----/\---- workaround startPolling() bug ----/\---- 
    } else {
    device.startPolling(5000);
    }

    device.on('device-offline', () => {
    logEvent('device-offline', device);
    });

    device.on('error', () => {
    logEvent('error', device);
    });

    device.on('polling-error', () => {
    logEvent('polling-error: stop polling:', device);
    device.stopPolling();
    });

});

client.on('error', () => { console.log('Oops'); } );

client.on('discovery-invalid', () => { console.log('Oops'); } );

process.on("unhandledRejection", event => {
    console.log('--- unhandledrejection ---', event);
});

console.log('Starting TP-Link Device Discovery');
client.startDiscovery();

Here are the results from the failing run:

pass = false Starting TP-Link Device Discovery Thu 5:35 PM device-new HS200(US) "recirculation pump" 10.0.0.110:9999 Thu 5:35 PM device-new HS105(US) "Living Room Lamp" 10.0.0.111:9999 Thu 5:35 PM device-new HS105(US) "stereo" 10.0.0.112:9999 [recirculation pump] device.send() Error: connect ENETUNREACH 10.0.0.110:9999 - Local (0.0.0.0:0) --- unhandledrejection --- { Error: connect ENETUNREACH 10.0.0.110:9999 - Local (0.0.0.0:0) at internalConnect (net.js:881:16) at defaultTriggerAsyncIdScope (internal/async_hooks.js:294:19) at defaultTriggerAsyncIdScope (net.js:971:9) at process._tickCallback (internal/process/next_tick.js:61:11) errno: 'ENETUNREACH', code: 'ENETUNREACH', syscall: 'connect', address: '10.0.0.110', port: 9999 } [Living Room Lamp] device.send() Error: connect ENETUNREACH 10.0.0.111:9999 - Local (0.0.0.0:0) [stereo] device.send() Error: connect ENETUNREACH 10.0.0.112:9999 - Local (0.0.0.0:0) --- unhandledrejection --- { Error: connect ENETUNREACH 10.0.0.111:9999 - Local (0.0.0.0:0) at internalConnect (net.js:881:16) at defaultTriggerAsyncIdScope (internal/async_hooks.js:294:19) at defaultTriggerAsyncIdScope (net.js:971:9) at process._tickCallback (internal/process/next_tick.js:61:11) errno: 'ENETUNREACH', code: 'ENETUNREACH', syscall: 'connect', address: '10.0.0.111', port: 9999 } --- unhandledrejection --- { Error: connect ENETUNREACH 10.0.0.112:9999 - Local (0.0.0.0:0) at internalConnect (net.js:881:16) at defaultTriggerAsyncIdScope (internal/async_hooks.js:294:19) at defaultTriggerAsyncIdScope (net.js:971:9) at process._tickCallback (internal/process/next_tick.js:61:11) errno: 'ENETUNREACH', code: 'ENETUNREACH', syscall: 'connect', address: '10.0.0.112', port: 9999 }

And, here are the passing results, where I used device.myStartPolling instead of Device.startPolling:

pass = true Starting TP-Link Device Discovery Thu 5:35 PM device-new HS200(US) "recirculation pump" 10.0.0.110:9999 Thu 5:35 PM device-new HS105(US) "stereo" 10.0.0.112:9999 Thu 5:35 PM device-new HS105(US) "Living Room Lamp" 10.0.0.111:9999 [recirculation pump] device.send() Error: connect ENETUNREACH 10.0.0.110:9999 - Local (0.0.0.0:0) [stereo] device.send() Error: connect ENETUNREACH 10.0.0.112:9999 - Local (0.0.0.0:0) Thu 5:35 PM polling-error: stop polling: HS200(US) "recirculation pump" 10.0.0.110:9999 Thu 5:35 PM polling-error: stop polling: HS105(US) "stereo" 10.0.0.112:9999 [Living Room Lamp] device.send() Error: connect ENETUNREACH 10.0.0.111:9999 - Local (0.0.0.0:0) Thu 5:35 PM polling-error: stop polling: HS105(US) "Living Room Lamp" 10.0.0.111:9999

When I used device.myStartPolling, I go a "polling-error" event. When I use Device.startPolling, I got an unhandledRejection.

plasticrake commented 4 years ago

I'm still not able to replicate this issue, at least not in the current version. I don't get any unhandled rejections.

tplink-smarthome-api: v2.0.0 node --version: v12.16.3

const debug = require("debug")("poll");
const { Client } = require("tplink-smarthome-api");

const validHost = "10.0.1.160";
const unreachableHost = "192.0.2.0";

const client = new Client();

debug("Attempting to get device");
client.getDevice({ host: validHost }).then((device) => {
  debug("Got device");

  device.host = unreachableHost;
  device.startPolling(1000);

  device.on("polling-error", (err) => {
    debug("polling-error");
    console.dir(err);
  });
});
$  DEBUG=poll node poll.js

  poll Attempting to get device +0ms
  poll Got device +391ms
TCP 192.0.2.0:9999 Error: TCP Timeout
    at Timeout._onTimeout (/Users/patrick/Code/tptest/node_modules/tplink-smarthome-api/lib/network/tcp-socket.js:62:22)
    at listOnTimeout (internal/timers.js:549:17)
    at processTimers (internal/timers.js:492:7)
  poll polling-error +10s
Error: TCP Timeout
    at Timeout._onTimeout (/Users/patrick/Code/tptest/node_modules/tplink-smarthome-api/lib/network/tcp-socket.js:62:22)
    at listOnTimeout (internal/timers.js:549:17)
    at processTimers (internal/timers.js:492:7)

And when I disable my networking:

  poll polling-error +1s
Error: connect ENETUNREACH 192.0.2.0:9999 - Local (0.0.0.0:52343)
    at internalConnect (net.js:921:16)
    at defaultTriggerAsyncIdScope (internal/async_hooks.js:296:12)
    at net.js:1011:9
    at processTicksAndRejections (internal/process/task_queues.js:79:11) {
  errno: 'ENETUNREACH',
  code: 'ENETUNREACH',
  syscall: 'connect',
  address: '192.0.2.0',
  port: 9999
}
TCP 192.0.2.0:9999 Error: connect ENETUNREACH 192.0.2.0:9999 - Local (0.0.0.0:52346)
    at internalConnect (net.js:921:16)
    at defaultTriggerAsyncIdScope (internal/async_hooks.js:296:12)
    at net.js:1011:9
    at processTicksAndRejections (internal/process/task_queues.js:79:11) {
  errno: 'ENETUNREACH',
  code: 'ENETUNREACH',
  syscall: 'connect',
  address: '192.0.2.0',
  port: 9999
}
  poll polling-error +1s
Error: connect ENETUNREACH 192.0.2.0:9999 - Local (0.0.0.0:52346)
    at internalConnect (net.js:921:16)
    at defaultTriggerAsyncIdScope (internal/async_hooks.js:296:12)
    at net.js:1011:9
    at processTicksAndRejections (internal/process/task_queues.js:79:11) {
  errno: 'ENETUNREACH',
  code: 'ENETUNREACH',
  syscall: 'connect',
  address: '192.0.2.0',
  port: 9999
}
TCP 192.0.2.0:9999 Error: connect ENETUNREACH 192.0.2.0:9999 - Local (0.0.0.0:52347)
    at internalConnect (net.js:921:16)
    at defaultTriggerAsyncIdScope (internal/async_hooks.js:296:12)
    at net.js:1011:9
    at processTicksAndRejections (internal/process/task_queues.js:79:11) {
  errno: 'ENETUNREACH',
  code: 'ENETUNREACH',
  syscall: 'connect',
  address: '192.0.2.0',
  port: 9999
}
DavidBurg commented 4 years ago

@plasticrake, I'm running:

tplink-smarthome-api: v2.0.0
node --version: v12.16.3

I don't have a system set up to run the versions that you tested. I can try to set-up a system with those versions and rerun my test, but it might take a while. Were you able to run the short example that I provided and, if so, did it not demonstrate the problem?

I just browsed your most recent code and see that you are still using the try/catch block that MDN specifically says might not work.

Thanks for looking into this.

plasticrake commented 4 years ago

@DavidBurg see #95

DavidBurg commented 4 years ago

@plasticrake Thanks. I ran some tests with different versions of nodejs and tplink-smarthome-api on docker. I got variable stack traces on the ENETUNREACH error, but no unhandled rejections after 1.2.0. So, I think 1.3.0 fixed the problem.