Separate Dimmers appears broken

[brianhackel]

Describe the bug Ceiling fan with single light and separate dimmer switches (one for increase, one for decrease). Toggling the decreaseBrightness switch appears to do nothing (no debug logs at all appear). Toggling the increaseBrightness switch works, but provides error output in the log.

Information:

• Plugin version: homebridge-bond@3.0.0
• Bond firmware version: v2.14.5
• How homebridge is run: Homebridge UI

Logs [10/4/2020, 23:35:14] [Bond] Request (185d3dde2a528000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] [10/4/2020, 23:35:14] [Bond] Request (185d3dde2a538000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/StartIncreasingBrightness] [10/4/2020, 23:35:14] [Bond] Request (185d3dde2a544000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] [10/4/2020, 23:35:14] [Bond] Request (185d3dde2a54c000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/StartDecreasingBrightness] [10/4/2020, 23:35:14] [Bond] UDP Message received from 10.0.1.81:30007 - {"B":"ZZCC63460","t":"devices/1bd1b3e6/state","i":"050000b10ccabc21","f":100,"s":200,"m":0,"x":"bond","b":{"power":1,"speed":1,"light":1,"":"f4d12d19"}} [10/4/2020, 23:35:14] [Bond] [Office Ceiling fan] Received new state: {"power":1,"speed":1,"light":1,"":"f4d12d19"} [10/4/2020, 23:35:14] [Bond] Response (185d3dde2a528000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] - {"":"60b92918"} [10/4/2020, 23:35:14] [Bond] UDP Message received from 10.0.1.81:30007 - {"B":"ZZCC63460","t":"devices/1bd1b3e6/state","i":"050000d771211b8d","f":100,"s":200,"m":0,"x":"bond","b":{"power":1,"speed":1,"light":1,"":"f4d12d19"}} [10/4/2020, 23:35:14] [Bond] [Office Ceiling fan] Received new state: {"power":1,"speed":1,"light":1,"":"f4d12d19"} [10/4/2020, 23:35:14] [Bond] Response (185d3dde2a538000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/StartIncreasingBrightness] - {"":"8ca95ae8"} [10/4/2020, 23:35:14] [Bond] [Office Ceiling fan] Increased Brightness: true [10/4/2020, 23:35:14] [Bond] UDP Message received from 10.0.1.81:30007 - {"B":"ZZCC63460","t":"devices/1bd1b3e6/state","i":"050000ca80096c69","f":100,"s":200,"m":0,"x":"bond","b":{"power":1,"speed":1,"light":1,"":"f4d12d19"}} [10/4/2020, 23:35:14] [Bond] [Office Ceiling fan] Received new state: {"power":1,"speed":1,"light":1,"":"f4d12d19"} [10/4/2020, 23:35:14] [Bond] Response (185d3dde2a544000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] - {"":"60b92918"} [10/4/2020, 23:35:16] [Front Door Camera] calling get(): true [10/4/2020, 23:35:16] [Bond] UDP Message received from 10.0.1.81:30007 - {"B":"ZZCC63460","t":"devices/1bd1b3e6/state","i":"050000591758e0db","f":100,"s":200,"m":0,"x":"bond","b":{"power":1,"speed":1,"light":1,"":"f4d12d19"}} [10/4/2020, 23:35:16] [Bond] [Office Ceiling fan] Received new state: {"power":1,"speed":1,"light":1,"":"f4d12d19"} [10/4/2020, 23:35:16] [Bond] Response (185d3dde2a54c000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/StartDecreasingBrightness] - {"":"7f3143a2"} [10/4/2020, 23:35:16] [Bond] [Office Ceiling fan] Error decreasing brightness: Error: This callback function has already been called by someone else; it can only be called one time. [10/4/2020, 23:35:20] [Bond] Request (185d3dde30c4c000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] [10/4/2020, 23:35:20] [Bond] Request (185d3dde30c54000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] [10/4/2020, 23:35:20] [Bond] UDP Message received from 10.0.1.81:30007 - {"B":"ZZCC63460","t":"devices/1bd1b3e6/state","i":"05000060d940bd4d","f":100,"s":200,"m":0,"x":"bond","b":{"power":1,"speed":1,"light":1,"":"f4d12d19"}} [10/4/2020, 23:35:20] [Bond] [Office Ceiling fan] Received new state: {"power":1,"speed":1,"light":1,"":"f4d12d19"} [10/4/2020, 23:35:20] [Bond] Response (185d3dde30c4c000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] - {"":"60b92918"} [10/4/2020, 23:35:20] [Bond] [Office Ceiling fan] Increased Brightness: false [10/4/2020, 23:35:21] [Bond] UDP Message received from 10.0.1.81:30007 - {"B":"ZZCC63460","t":"devices/1bd1b3e6/state","i":"0500002ba82cb8ef","f":100,"s":200,"m":0,"x":"bond","b":{"power":1,"speed":1,"light":1,"":"f4d12d19"}} [10/4/2020, 23:35:21] [Bond] [Office Ceiling fan] Received new state: {"power":1,"speed":1,"light":1,"":"f4d12d19"} [10/4/2020, 23:35:21] [Bond] Response (185d3dde30c54000) [put http://10.0.1.81/v2/devices/1bd1b3e6/actions/Stop] - {"":"60b92918"} [10/4/2020, 23:35:21] [Bond] [Office Ceiling fan] Error decreasing brightness: Error: This callback function has already been called by someone else; it can only be called one time

Additionally, i tried to debug myself by updating my forked repo, and adding some additional logging, but executing 'npm run dev' produces the following:

homebridge-bond@3.0.0 dev /home//homebridge-bond tsc --watch & nodemon dist [nodemon] 2.0.4 [nodemon] to restart at any time, enter rs [nodemon] watching path(s): . [nodemon] watching extensions: js,mjs,json [nodemon] starting node dist dist/index.js ..... ...... [23:41:54] Starting compilation in watch mode...

internal/modules/cjs/loader.js:969 throw err; ^

Error: Cannot find module '/home//homebridge-bond/dist/index.js' at Function.Module._resolveFilename (internal/modules/cjs/loader.js:966:15) at Function.Module._load (internal/modules/cjs/loader.js:842:27) at Function.executeUserEntryPoint [as runMain] (internal/modules/run_main.js:71:12) at internal/main/run_main_module.js:17:47 { code: 'MODULE_NOT_FOUND', requireStack: [] } [nodemon] app crashed - waiting for file changes before starting...

I did not have problems building with npm run dev with my previous pull request, which was just prior to the change from TSLint to ESLint

[aarons22]

Thanks @brianhackel - I tried to refactor this part of the plugin as best I could to fit into the new format, but apparently I missed! Before running npm run dev can you delete the /dist folder (which contains the generated js code and run npm install? This seems like an issue related to old generated code or mismatched dependencies. I also wonder if your node version has an impact.

As for the actual issue, these logs should help identify the bug. I'll try to check it out this week

[aarons22]

I looked through the logs and I can't quite tell what's going on. Seems like one of the callbacks isn't getting fired, but it's tough to tell without having the same configuration on my end. Let me know if you were able to build the plugin locally and debug.

[brianhackel]

npm install does not generate a /dist folder. and i still get the same error when trying npm run dev. my setup is that i have the git repo cloned to my home directory and then npm link'd to /usr/lib/homebridge. but homebridge won't start in this configuration because the plugin is not built, and i can't seem to get it to build anymore. i didn't have a problem when i submitted my PR a while ago, but then i removed my git repo and just re-installed direct from npm.

[brianhackel]

I got it building. but i had to run npm run build FIRST. That created the /dist directory; then from there, i could execute a separate login and run npm run dev which would watch and launch incremental builds as i edited the typescript.

anyway, i noticed that once i had purged the particular ceiling fan from my cache (as part of the resolution for the light brightness issue #112), ONLY the Increase Brightness switch was appearing for that accessory.

I believe the issue is around line 70 in Services.ts:

    // Check for service by subtype, then fallback to service by id only (mainly for legacy services)
    let service = accessory.getServiceById(platform.Service.Switch, subType) || accessory.getService(platform.Service.Switch);
    if (service === undefined) {
      service = accessory.addService(platform.Service.Switch, name, subType);
    }

I think when CeilingFanAccessory creates the new switch service for the Decrease Brightness switch at line 76, the OR'd accessory.getService(platform.Service.Switch) returns the other Switch that was just created for Increase Brightness. Thus, we skip the conditional to actually add the service and instead have a handle to the previously-created Increase Brightness service. That's how the wires get crossed on the callbacks.

I removed that second OR'd statement, and it appears to work, but i don't know what the ripple consequences might be for "legacy services" so i'm not too confident to say that's the actual fix. I think the consequence of having that statement there though was that no accessory could have more than one switch service configured. and might the same problem befall the ButtonService if ever there is an accessory that tries to create two different ButtonServices?

[aarons22]

Attempted to fix in 3.2.0! Please validate and let me know how it goes.

[brianhackel]

Sorry, didn't report back. Looks good now.