search

FlyingDiver / Indigo-MyQ

Plugin for Indigo home automation system to control MyQ devices
MIT License
8 stars 2 forks source link

Plugin Becomes Unresponsive #20

Closed IBC-IT closed 3 years ago

IBC-IT commented 3 years ago

Seem that the plugin only work for a few minutes and then fail.

MyQ Error                       actionControlDevice: Unsupported action requested: actionValue : ActionProps : (dict)
configured : True
delayAmount : 900
description : unlock device
deviceAction : Unlock
deviceId : 595617506
replaceExisting : True
textToSpeak :  for Garage Door 1
FlyingDiver commented 3 years ago

Is this repeatable? Please turn on debug logging and do the sequence again.

IBC-IT commented 3 years ago

Seem that errors are varied. But once the plugin hits one error, it never recovers until the it is restarted.

MyQ                             Closing garage door Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to close Garage Door 2: Device is currently closing, wait until complete."}
   MyQ Error                       Error when trying to close Garage Door 2: Device is currently closing, wait until complete.
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Device Garage Door 2 is closing"}
   MyQ                             Device Garage Door 2 is closing
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Failed to close garage door Garage Door 2."}
   MyQ                             Failed to close garage door Garage Door 2.
IBC-IT commented 3 years ago 
   MyQ Error                       actionControlDevice: Unsupported action requested: actionValue : ActionProps : (dict)
configured : True
delayAmount : 900
description : lock device
deviceAction : Lock
deviceId : 1346031976
replaceExisting : True
textToSpeak :  for Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "close", "id": "CG084619EE62"}}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Closing garage door Garage Door 2"}
   MyQ                             Closing garage door Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to close Garage Door 2: Device is currently closing, wait until complete."}
   MyQ Error                       Error when trying to close Garage Door 2: Device is currently closing, wait until complete.
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Device Garage Door 2 is closing"}
   MyQ                             Device Garage Door 2 is closing
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Failed to close garage door Garage Door 2."}
   MyQ                             Failed to close garage door Garage Door 2.
FlyingDiver commented 3 years ago

I'm at a loss on why you're getting the initial Unsupported action error.

IBC-IT commented 3 years ago

I am using the MYQ-G0301, if that helps.

IBC-IT commented 3 years ago

This is using the pre-lease version 7.6. The official one is not even able to find any connected devices.

FlyingDiver commented 3 years ago

Post the log info from the "Write MyQ Data to Log" menu command.

IBC-IT commented 3 years ago 
{
"CG084619EE": {
        "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99",
        "created_date": "0001-01-01T00:00:00",
        "device_family": "garagedoor",
        "device_model": "virtualgaragedooropener",
        "device_platform": "myq",
        "device_type": "virtualgaragedooropener",
        "href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE61",
        "name": "Garage Door 1",
        "parent_device_id": "GW23001AA827",
        "serial_number": "CG084619EE61",
        "state": {
            "attached_camera_serial_number": "",
            "door_state": "closed",
            "dps_battery_critical": false,
            "dps_low_battery_mode": false,
            "dps_no_communication": false,
            "is_unattended_close_allowed": true,
            "is_unattended_open_allowed": true,
            "last_status": "2021-05-07T04:34:25.8885923Z",
            "last_update": "2021-05-07T04:29:16.7895024Z",
            "monitor_only_mode": false,
            "number_of_learned_dps_devices": 1,
            "online": true,
            "sensor_comm_error": false
        }
    },
    "CG084619EE62": {
        "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99",
        "created_date": "0001-01-01T00:00:00",
        "device_family": "garagedoor",
        "device_model": "virtualgaragedooropener",
        "device_platform": "myq",
        "device_type": "virtualgaragedooropener",
        "href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE62",
        "name": "Garage Door 2",
        "parent_device_id": "GW23001AA827",
        "serial_number": "CG084619EE62",
        "state": {
            "attached_camera_serial_number": "",
            "door_state": "closed",
            "dps_battery_critical": false,
            "dps_low_battery_mode": false,
            "dps_no_communication": false,
            "is_unattended_close_allowed": true,
            "is_unattended_open_allowed": true,
            "last_status": "2021-05-07T04:36:10.0318256Z",
            "last_update": "2021-05-07T04:36:09.9749113Z",
            "monitor_only_mode": false,
            "number_of_learned_dps_devices": 1,
            "online": true,
            "sensor_comm_error": false
        }
    },
    "GW23001AA827": {
        "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99",
        "created_date": "0001-01-01T00:00:00",
        "device_family": "gateway",
        "device_model": "hub",
        "device_platform": "myq",
        "device_type": "hub",
        "href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/gateway/GW23001AA827",
        "name": "MyQ Hub",
        "serial_number": "GW23001AA827",
        "state": {
            "allow_bluetooth_lock": false,
            "firmware_version": "3.4",
            "homekit_capable": false,
            "homekit_enabled": false,
            "last_status": "2021-05-06T14:28:38.1794251Z",
            "learn_mode": false,
            "online": true,
            "pending_bootload_abandoned": false,
            "physical_devices": [
                "CG084619EE61",
                "CG084619EE62"
            ],
            "updated_date": "2021-05-06T14:28:42.1820483Z",
            "wifi_rssi_decibel_milliwatts": -59,
            "wifi_signal_strength": "good"
        }
    }
}
FlyingDiver commented 3 years ago

Did the beginning of that get truncated? It's missing a { and " at a minimum.

FlyingDiver commented 3 years ago

I need to look at the code, those "virtual" openers have different property values than the real MyQ openers.

FlyingDiver commented 3 years ago

OK, no problems apparent in that data. The plugin only looks at a few of the device properties, and all of those look fine for the virtual openers. Still clueless on how an opener device could trigger that error.

IBC-IT commented 3 years ago

Sorry, yes the log starts with:

MyQ MyQ Devices: { "CG084619EE61": {

FlyingDiver commented 3 years ago

Please run this command in the Indigo scripting shell (next to last item in Plugins menu): indigo.server.log(unicode(indigo.devices[1346031976]))

IBC-IT commented 3 years ago 
   Interactive Shell               
address : CG084619EE62
batteryLevel : None
buttonConfiguredCount : 0
buttonGroupCount : 0
configured : True
description : Single Door
deviceTypeId : myqOpener
displayStateId : onOffState
displayStateImageSel : Locked
displayStateValRaw : True
displayStateValUi : locked
enabled : True
energyAccumBaseTime : None
energyAccumTimeDelta : None
energyAccumTotal : None
energyCurLevel : None
errorState : 
folderId : 791498055
globalProps : MetaProps : (dict)
     com.flyingdiver.indigoplugin.myq : (dict)
          IsLockSubType : true (bool)
          address : CG084619EE62 (string)
          devVersCount : 2 (integer)
          myqID : CG084619EE62 (string)
          sensor :  (string)
id : 1346031976
lastChanged : 2021-05-07 10:19:04
lastSuccessfulComm : 2021-05-07 10:19:04
ledStates : []
model : MyQ Door Opener
name : Garage Door 2
onState : True
ownerProps : com.flyingdiver.indigoplugin.myq : (dict)
     IsLockSubType : true (bool)
     address : CG084619EE62 (string)
     devVersCount : 2 (integer)
     myqID : CG084619EE62 (string)
     sensor :  (string)
pluginId : com.flyingdiver.indigoplugin.myq
pluginProps : emptyDict : (dict)
protocol : Plugin
remoteDisplay : True
sharedProps : com.indigodomo.indigoserver : (dict)
states : States : (dict)
     doorStatus : closed (string)
     doorStatus.autoreverse : false (bool)
     doorStatus.closed : true (bool)
     doorStatus.closing : false (bool)
     doorStatus.open : false (bool)
     doorStatus.opening : false (bool)
     doorStatus.stopped : false (bool)
     doorStatus.transition : false (bool)
     doorStatus.unknown : false (bool)
     onOffState : on (on/off bool)
     onOffState.ui : locked (string)
subModel : 
supportsAllLightsOnOff : False
supportsAllOff : False
supportsStatusRequest : True
version : None
IBC-IT commented 3 years ago

Just tried to open one garage door after sending the above code. Here is what I get:

   MyQ Debug                       changeDeviceAction, deviceId = 1346031976, actionId = openDoor
   MyQ Debug                       Send pymyq message: {"cmd": "open", "id": "CG084619EE62"}
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "open", "id": "CG084619EE62"}}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Opening garage door Garage Door 2"}
   MyQ                             Opening garage door Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to open Garage Door 2: Error requesting data from https://account-devices-gdo.myq-cloud.com/api/v5.2/Accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/door_openers/CG084619EE62/open: 401 - Unauthorized"}
   MyQ Error                       Error when trying to open Garage Door 2: Error requesting data from https://account-devices-gdo.myq-cloud.com/api/v5.2/Accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/door_openers/CG084619EE62/open: 401 - Unauthorized

May 7, 2021 at 10:21:56 AM
   MyQ Debug                       Send pymyq message: {"cmd": "accounts"}
   MyQ Debug                       Send pymyq message: {"cmd": "devices"}
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "accounts"}}
   MyQ Debug                       Received pymyq message: {"msg": "account", "id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "name": "Ukie Home"}
   MyQ Debug                       pymyq_read: account ID = d49f9932-bfaa-45c4-bb4c-c0e9b477ef99, name = Ukie Home
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "devices"}}
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "CG084619EE61", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE61", "serial_number": "CG084619EE61", "device_family": "garagedoor", "device_platform": "myq", "device_type": "virtualgaragedooropener", "device_model": "virtualgaragedooropener", "name": "Garage Door 1", "parent_device_id": "GW23001AA827", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"dps_battery_critical": false, "dps_no_communication": false, "dps_low_battery_mode": false, "monitor_only_mode": false, "number_of_learned_dps_devices": 1, "sensor_comm_error": false, "attached_camera_serial_number": "", "door_state": "closed", "last_update": "2021-05-07T04:29:16.7895024Z", "is_unattended_open_allowed": true, "is_unattended_close_allowed": true, "online": true, "last_status": "2021-05-07T04:34:25.8885923Z"}}}
   MyQ Debug                       pymyq_read: device ID = CG084619EE61, name = Garage Door 1, family = garagedoor
   MyQ Debug                       pymyq_read: door state = closed
   MyQ Debug                       Checking Opener Device: Garage Door 1 (CG084619EE61) against CG084619EE61
   MyQ Debug                       Skipping triggers, no linked sensor for MyQ device Garage Door 1
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "CG084619EE62", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE62", "serial_number": "CG084619EE62", "device_family": "garagedoor", "device_platform": "myq", "device_type": "virtualgaragedooropener", "device_model": "virtualgaragedooropener", "name": "Garage Door 2", "parent_device_id": "GW23001AA827", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"dps_battery_critical": false, "dps_no_communication": false, "dps_low_battery_mode": false, "monitor_only_mode": false, "number_of_learned_dps_devices": 1, "sensor_comm_error": false, "attached_camera_serial_number": "", "door_state": "closed", "last_update": "2021-05-07T04:36:09.9749113Z", "is_unattended_open_allowed": true, "is_unattended_close_allowed": true, "online": true, "last_status": "2021-05-07T04:36:10.0318256Z"}}}
   MyQ Debug                       pymyq_read: device ID = CG084619EE62, name = Garage Door 2, family = garagedoor
   MyQ Debug                       pymyq_read: door state = closed
   MyQ Debug                       Checking Opener Device: Garage Door 1 (CG084619EE61) against CG084619EE62
   MyQ Debug                       Checking Opener Device: Garage Door 2 (CG084619EE62) against CG084619EE62
   MyQ Debug                       Skipping triggers, no linked sensor for MyQ device Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "GW23001AA827", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/gateway/GW23001AA827", "serial_number": "GW23001AA827", "device_family": "gateway", "device_platform": "myq", "device_type": "hub", "device_model": "hub", "name": "MyQ Hub", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"allow_bluetooth_lock": false, "firmware_version": "3.4", "homekit_capable": false, "homekit_enabled": false, "learn_mode": false, "updated_date": "2021-05-06T14:28:42.1820483Z", "physical_devices": ["CG084619EE61", "CG084619EE62"], "pending_bootload_abandoned": false, "wifi_rssi_decibel_milliwatts": -59, "wifi_signal_strength": "good", "online": true, "last_status": "2021-05-06T14:28:38.1794251Z"}}}
   MyQ Debug                       pymyq_read: device ID = GW23001AA827, name = MyQ Hub, family = gateway
IBC-IT commented 3 years ago

Once the plugin is relaunched, all is working again.

FlyingDiver commented 3 years ago

Post the restart log lines. The error above says that it lost authentication, at which point I wouldn't expect anything to work.

IBC-IT commented 3 years ago 
   Reloading plugin "MyQ 7.6.0"
   Stopping plugin "MyQ 7.6.0" (pid 60450)
   MyQ Debug                       Garage Door 1: deviceStopComm: Removing device (595617506) from MyQ device list
   MyQ Debug                       Garage Door 2: deviceStopComm: Removing device (1346031976) from MyQ device list
   MyQ                             Stopping MyQ
   Stopped plugin "MyQ 7.6.0"
   Starting plugin "MyQ 7.6.0" (pid 75072)
   Started plugin "MyQ 7.6.0"
   MyQ                             Starting MyQ
   MyQ Debug                       statusFrequency = 360.0
   MyQ Debug                       Garage Door 1: deviceStartComm: Device version is up to date (2)
   MyQ Debug                       Garage Door 1: deviceStartComm: Adding device (595617506) to MyQ device list
   MyQ Debug                       Garage Door 2: deviceStartComm: Device version is up to date (2)
   MyQ Debug                       Garage Door 2: deviceStartComm: Adding device (1346031976) to MyQ device list
   MyQ Debug                       Send pymyq message: {"cmd": "accounts"}
   MyQ Debug                       Send pymyq message: {"cmd": "devices"}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Login Complete"}
   MyQ                             Login Complete
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "accounts"}}
   MyQ Debug                       Received pymyq message: {"msg": "account", "id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "name": "Ukie Home"}
   MyQ Debug                       pymyq_read: account ID = d49f9932-bfaa-45c4-bb4c-c0e9b477ef99, name = Ukie Home
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "devices"}}
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "CG084619EE61", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE61", "serial_number": "CG084619EE61", "device_family": "garagedoor", "device_platform": "myq", "device_type": "virtualgaragedooropener", "device_model": "virtualgaragedooropener", "name": "Garage Door 1", "parent_device_id": "GW23001AA827", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"dps_battery_critical": false, "dps_no_communication": false, "dps_low_battery_mode": false, "monitor_only_mode": false, "number_of_learned_dps_devices": 1, "sensor_comm_error": false, "attached_camera_serial_number": "", "door_state": "closed", "last_update": "2021-05-07T04:29:16.7895024Z", "is_unattended_open_allowed": true, "is_unattended_close_allowed": true, "online": true, "last_status": "2021-05-07T17:23:43.6704776Z"}}}
   MyQ Debug                       pymyq_read: device ID = CG084619EE61, name = Garage Door 1, family = garagedoor
   MyQ Debug                       pymyq_read: door state = closed
   MyQ Debug                       Checking Opener Device: Garage Door 1 (CG084619EE61) against CG084619EE61
   MyQ Debug                       Skipping triggers, no linked sensor for MyQ device Garage Door 1
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "CG084619EE62", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE62", "serial_number": "CG084619EE62", "device_family": "garagedoor", "device_platform": "myq", "device_type": "virtualgaragedooropener", "device_model": "virtualgaragedooropener", "name": "Garage Door 2", "parent_device_id": "GW23001AA827", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"dps_battery_critical": false, "dps_no_communication": false, "dps_low_battery_mode": false, "monitor_only_mode": false, "number_of_learned_dps_devices": 1, "sensor_comm_error": false, "attached_camera_serial_number": "", "door_state": "closed", "last_update": "2021-05-07T04:36:09.9749113Z", "is_unattended_open_allowed": true, "is_unattended_close_allowed": true, "online": true, "last_status": "2021-05-07T17:23:43.7322456Z"}}}
   MyQ Debug                       pymyq_read: device ID = CG084619EE62, name = Garage Door 2, family = garagedoor
   MyQ Debug                       pymyq_read: door state = closed
   MyQ Debug                       Checking Opener Device: Garage Door 1 (CG084619EE61) against CG084619EE62
   MyQ Debug                       Checking Opener Device: Garage Door 2 (CG084619EE62) against CG084619EE62
   MyQ Debug                       Skipping triggers, no linked sensor for MyQ device Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "GW23001AA827", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/gateway/GW23001AA827", "serial_number": "GW23001AA827", "device_family": "gateway", "device_platform": "myq", "device_type": "hub", "device_model": "hub", "name": "MyQ Hub", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"allow_bluetooth_lock": false, "firmware_version": "3.8", "homekit_capable": false, "homekit_enabled": false, "learn_mode": false, "updated_date": "2021-05-07T06:07:35.9049155Z", "physical_devices": ["CG084619EE61", "CG084619EE62"], "pending_bootload_abandoned": false, "wifi_rssi_decibel_milliwatts": -49, "wifi_signal_strength": "excellent", "online": true, "last_status": "2021-05-07T06:07:31.8993175Z"}}}
   MyQ Debug                       pymyq_read: device ID = GW23001AA827, name = MyQ Hub, family = gateway
FlyingDiver commented 3 years ago

Forgot I'm not going to see any of the login messages with this version of the plugin. Because the actual Python3 code talking to the MyQ servers is running in a subprocess, it doesn't log to the Indigo log files. Use the "Plugins->MyQ->Reload in Interactive Shell" menu command to restart the plugin. A Terminal window will pop up. When the error appears again, copy the contents of the Terminal window and post here.

IBC-IT commented 3 years ago

I do not have the option "Reload in Interactive Shell" Is that in the official release?

FlyingDiver commented 3 years ago

I forgot, you need to enable it:

Screen Shot 2021-05-07 at 1 50 01 PM
IBC-IT commented 3 years ago

So this time around it becomes unresponsive to the second gardge door:

   MyQ Debug                       changeDeviceAction, deviceId = 1346031976, actionId = closeDoor
   MyQ Debug                       Send pymyq message: {"cmd": "close", "id": "CG084619EE62"}
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "close", "id": "CG084619EE62"}}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Closing garage door Garage Door 2"}
   MyQ                             Closing garage door Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to close Garage Door 2: Device is currently closing, wait until complete."}
   MyQ Error                       Error when trying to close Garage Door 2: Device is currently closing, wait until complete.
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Device Garage Door 2 is closing"}
   MyQ                             Device Garage Door 2 is closing
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Garage door Garage Door 2 has been closed."}
   MyQ                             Garage door Garage Door 2 has been closed.

Seem to be struggling to get the open/close status. Says "has been closed" in log, but it is not, and Indigo says "unlocked"

FlyingDiver commented 3 years ago

So there's two issues here. One is the authentication error, if it's repeatable. The second is that this version of the plugin doesn't seem to be dealing well with multiple messages regarding the closing status. I will see if I can do anything about that.

FlyingDiver commented 3 years ago

So just to be clear, from that last log section, you sent the close command, but the door never did close?

IBC-IT commented 3 years ago

So just to be clear, from that last log section, you sent the close command, but the door never did close?

Correct.

IBC-IT commented 3 years ago

I still did not get the authentication error, but I am getting this:

   MyQ Debug                       actionControlDevice: Lock Garage Door 2
   MyQ Debug                       Send pymyq message: {"cmd": "close", "id": "CG084619EE62"}
   MyQ Error                       actionControlDevice: Unsupported action requested: actionValue : ActionProps : (dict)
configured : True
delayAmount : 900
description : lock device
deviceAction : Lock
deviceId : 1346031976
replaceExisting : True
textToSpeak :  for Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "close", "id": "CG084619EE62"}}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Closing garage door Garage Door 2"}
   MyQ                             Closing garage door Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to close Garage Door 2: Device is currently closing, wait until complete."}
   MyQ Error                       Error when trying to close Garage Door 2: Device is currently closing, wait until complete.
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Device Garage Door 2 is closing"}
   MyQ                             Device Garage Door 2 is closing
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Failed to close garage door Garage Door 2."}
   MyQ                             Failed to close garage door Garage Door 2.
FlyingDiver commented 3 years ago

Oh crap. I see a bug in my code. Hold on....

IBC-IT commented 3 years ago

Garage Door 1 is still responsive, but not door 2

FlyingDiver commented 3 years ago

Try 7.6.1: https://github.com/FlyingDiver/Indigo-MyQ/releases/tag/7.6.1

IBC-IT commented 3 years ago

Testing it now. Is there a reason why there is about 10 sec delay between the log showing: MyQ Garage door Garage Door 1 has been opened.

and that status registering on the indigo device itself?

FlyingDiver commented 3 years ago

The first is the API reporting that the door was opened. The second is the plugin actually getting an update from the MyQ servers that it's actually open.

IBC-IT commented 3 years ago

The first is the API reporting that the door was opened. The second is the plugin actually getting an update from the MyQ servers that it's actually open.

So it can take that long to process that request? On the close, however, it is more in sync.

IBC-IT commented 3 years ago

Try 7.6.1: https://github.com/FlyingDiver/Indigo-MyQ/releases/tag/7.6.1

Seems to be working fine so far. Will update if I get authentication error again.

FlyingDiver commented 3 years ago

Just keep in mind that Indigo only has two states - open or close, while MyQ has several more. So in-transit (moving) is reported as open even if it's not completely open (or closed) yet.

IBC-IT commented 3 years ago

Not sure if we need a new thread for this, but I just opened garage 1, log says:

MyQ Debug actionControlDevice: Unlock Garage Door 1 MyQ Debug Send pymyq message: {"cmd": "open", "id": "CG084619EE61"} MyQ Debug Received pymyq message: {"msg": "echo", "request": {"cmd": "open", "id": "CG084619EE61"}} MyQ Debug Received pymyq message: {"msg": "status", "status": "Opening garage door Garage Door 1"} MyQ Opening garage door Garage Door 1 MyQ Debug Received pymyq message: {"msg": "status", "status": "Garage door Garage Door 1 has been opened."} MyQ Garage door Garage Door 1 has been opened.

But it took about 2 minutes for the device state to update...

Would be helpful to have those several other states like "opening" to be instantly pulled into the device state, since they are already in the log. Or is it not possible to add additional custom fields to a garage device?

FlyingDiver commented 3 years ago

Yeah, the older API didn't report those intermediate states unless I polled for them, and they're in the doorState custom state. I'm not currently updating doorState based on the intermediate log entries. That would be a separate enhancement request. I don't consider the delay to be a bug.

IBC-IT commented 3 years ago

Yeah, the older API didn't report those intermediate states unless I polled for them, and they're in the doorState custom state. I'm not currently updating doorState based on the intermediate log entries. That would be a separate enhancement request. I don't consider the delay to be a bug.

Should I log that request in GitHub or Indigo form?

FlyingDiver commented 3 years ago

GitHub for bugs or feature requests. Forums for Q&A.

FlyingDiver commented 3 years ago

Other than the delay in the status updates, is 7.6.1 working correctly?

IBC-IT commented 3 years ago

Just tried opening garage 2:

   MyQ Debug                       changeDeviceAction, deviceId = 1346031976, actionId = openDoor
   MyQ Debug                       Send pymyq message: {"cmd": "open", "id": "CG084619EE62"}
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "open", "id": "CG084619EE62"}}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Opening garage door Garage Door 2"}
   MyQ                             Opening garage door Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to open Garage Door 2: Error requesting data from https://account-devices-gdo.myq-cloud.com/api/v5.2/Accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/door_openers/CG084619EE62/open: 401 - Unauthorized"}
   MyQ Error                       Error when trying to open Garage Door 2: Error requesting data from https://account-devices-gdo.myq-cloud.com/api/v5.2/Accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/door_openers/CG084619EE62/open: 401 - Unauthorized
   MyQ Debug                       Send pymyq message: {"cmd": "accounts"}
   MyQ Debug                       Send pymyq message: {"cmd": "devices"}
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "accounts"}}
   MyQ Debug                       Received pymyq message: {"msg": "account", "id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "name": "Ukie Home"}
   MyQ Debug                       pymyq_read: account ID = d49f9932-bfaa-45c4-bb4c-c0e9b477ef99, name = Ukie Home
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "devices"}}
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "CG084619EE61", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE61", "serial_number": "CG084619EE61", "device_family": "garagedoor", "device_platform": "myq", "device_type": "virtualgaragedooropener", "device_model": "virtualgaragedooropener", "name": "Garage Door 1", "parent_device_id": "GW23001AA827", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"dps_battery_critical": false, "dps_no_communication": false, "dps_low_battery_mode": false, "monitor_only_mode": false, "number_of_learned_dps_devices": 1, "sensor_comm_error": false, "attached_camera_serial_number": "", "door_state": "closed", "last_update": "2021-05-07T20:56:31.1267778Z", "is_unattended_open_allowed": true, "is_unattended_close_allowed": true, "online": true, "last_status": "2021-05-07T20:57:18.6955081Z"}}}
   MyQ Debug                       pymyq_read: device ID = CG084619EE61, name = Garage Door 1, family = garagedoor
   MyQ Debug                       pymyq_read: door state = closed
   MyQ Debug                       Checking Opener Device: Garage Door 1 (CG084619EE61) against CG084619EE61
   MyQ Debug                       Skipping triggers, no linked sensor for MyQ device Garage Door 1
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "CG084619EE62", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/garagedoor/CG084619EE62", "serial_number": "CG084619EE62", "device_family": "garagedoor", "device_platform": "myq", "device_type": "virtualgaragedooropener", "device_model": "virtualgaragedooropener", "name": "Garage Door 2", "parent_device_id": "GW23001AA827", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"dps_battery_critical": false, "dps_no_communication": false, "dps_low_battery_mode": false, "monitor_only_mode": false, "number_of_learned_dps_devices": 1, "sensor_comm_error": false, "attached_camera_serial_number": "", "door_state": "closed", "last_update": "2021-05-07T20:57:26.3602571Z", "is_unattended_open_allowed": true, "is_unattended_close_allowed": true, "online": true, "last_status": "2021-05-07T20:57:26.4008971Z"}}}
   MyQ Debug                       pymyq_read: device ID = CG084619EE62, name = Garage Door 2, family = garagedoor
   MyQ Debug                       pymyq_read: door state = closed
   MyQ Debug                       Checking Opener Device: Garage Door 1 (CG084619EE61) against CG084619EE62
   MyQ Debug                       Checking Opener Device: Garage Door 2 (CG084619EE62) against CG084619EE62
   MyQ Debug                       Skipping triggers, no linked sensor for MyQ device Garage Door 2
   MyQ Debug                       Received pymyq message: {"msg": "device", "id": "GW23001AA827", "props": {"href": "/accounts/d49f9932-bfaa-45c4-bb4c-c0e9b477ef99/devices/gateway/GW23001AA827", "serial_number": "GW23001AA827", "device_family": "gateway", "device_platform": "myq", "device_type": "hub", "device_model": "hub", "name": "MyQ Hub", "created_date": "0001-01-01T00:00:00", "account_id": "d49f9932-bfaa-45c4-bb4c-c0e9b477ef99", "state": {"allow_bluetooth_lock": false, "firmware_version": "3.8", "homekit_capable": false, "homekit_enabled": false, "learn_mode": false, "updated_date": "2021-05-07T20:56:58.4371195Z", "physical_devices": ["CG084619EE61", "CG084619EE62"], "pending_bootload_abandoned": false, "wifi_rssi_decibel_milliwatts": -46, "wifi_signal_strength": "excellent", "online": true, "last_status": "2021-05-07T20:56:58.4341935Z"}}}
   MyQ Debug                       pymyq_read: device ID = GW23001AA827, name = MyQ Hub, family = gateway
IBC-IT commented 3 years ago

Here is what the Terminal says:

Last login: Fri May  7 10:55:08 on ttys001

The default interactive shell is now zsh.
To update your account to use zsh, please run `chsh -s /bin/zsh`.
For more details, please visit https://support.apple.com/kb/HT208050.
/Library/Application\ Support/Perceptive\ Automation/Indigo\ 7.5/.debugPluginLaunch.command ; exit;
ukiews:~ server$ /Library/Application\ Support/Perceptive\ Automation/Indigo\ 7.5/.debugPluginLaunch.command ; exit;

Starting shell for plugin MyQ.indigoPlugin.
To access the plugin instance use the global named self.

Python 2.7.16 (default, Jun  5 2020, 22:59:21) 
[GCC 4.2.1 Compatible Apple LLVM 11.0.3 (clang-1103.0.29.20) (-macos10.15-objc-
Connected to Indigo Server v7.5.0, api v2.4 (localhost:1176)
Started Plugin MyQ v7.6.1
>>> Terminated: 15
logout
Saving session...2021-05-07 15:44:11.479 IndigoPluginHost[76417:1376402] Quitting Indigo Plugin Host - received quit signal

...copying shared history...Exception in thread Thread-2:
Traceback (most recent call last):
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 801, in __bootstrap_inner
    self.run()
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 754, in run
    self.__target(*self.__args, **self.__kwargs)
  File "plugin.py", line 106, in pymyq_read
    data = json.loads(msg)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/__init__.py", line 339, in loads
    return _default_decoder.decode(s)
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/decoder.py", line 364, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/json/decoder.py", line 382, in raw_decode
    raise ValueError("No JSON object could be decoded")
ValueError: No JSON object could be decoded

...saving history...truncating history files...
...completed.
IBC-IT commented 3 years ago

Looks like it is using the wrong version of Python? But I did install the latest version....

Would I need to uninstall 2.7?

FlyingDiver commented 3 years ago

No, it's fine. The window shows 2.7 because that's the version the main plugin is running under. There's a subprocess running 3.8, but it only writes to the terminal session if it has an error. The error there is the plugin failing to deal with possibly bad data coming back from the subprocess. I'll trap that error and have another version to test over the weekend.

FlyingDiver commented 3 years ago

Try https://github.com/FlyingDiver/Indigo-MyQ/releases/tag/7.6.2

IBC-IT commented 3 years ago

Plugin won't start now:

Enabling plugin "MyQ 7.6.2" Debugging plugin "MyQ 7.6.2" (pid 1938) MyQ Error Error in plugin execution InitializeMain:

Traceback (most recent call last): SyntaxError: ('invalid syntax', ('plugin.py', 110, 22, ' return\n'))

FlyingDiver commented 3 years ago

Wow. I really messed that up.

IBC-IT commented 3 years ago

Is it working on your machine?

FlyingDiver commented 3 years ago

7.6.3 is now: https://github.com/FlyingDiver/Indigo-MyQ/releases/tag/7.6.3

IBC-IT commented 3 years ago

It's launching now. After a few tests, I'm getting a similar error as before:

   MyQ                             Closing garage door Garage Door 1
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to close Garage Door 1: Device is currently closing, wait until complete."}
   MyQ Error                       Error when trying to close Garage Door 1: Device is currently closing, wait until complete.
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Device Garage Door 1 is closing"}
   MyQ                             Device Garage Door 1 is closing
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Failed to close garage door Garage Door 1."}
   MyQ                             Failed to close garage door Garage Door 1.

May 11, 2021 at 9:14:43 AM
   MyQ Debug                       actionControlDevice: Lock Garage Door 1
   MyQ Debug                       Send pymyq message: {"cmd": "close", "id": "CG084619EE61"}
   MyQ Debug                       Received pymyq message: {"msg": "echo", "request": {"cmd": "close", "id": "CG084619EE61"}}
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Closing garage door Garage Door 1"}
   MyQ                             Closing garage door Garage Door 1
   MyQ Debug                       Received pymyq message: {"msg": "error", "error": "Error when trying to close Garage Door 1: Device is currently closing, wait until complete."}
   MyQ Error                       Error when trying to close Garage Door 1: Device is currently closing, wait until complete.
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Device Garage Door 1 is closing"}
   MyQ                             Device Garage Door 1 is closing
   MyQ Debug                       Received pymyq message: {"msg": "status", "status": "Failed to close garage door Garage Door 1."}
   MyQ                             Failed to close garage door Garage Door 1.

After restarting the plugin, it is working again. Seems to be an issue related with how quickly you send commands to open/close between the two garage doors.

FlyingDiver commented 3 years ago

I don't see a time stamp on that first set of log entries. And I don't see a second command to the same or a different door. If you can recreate this, post the logs for the entire sequence, with time stamps and annotations as needed, but do not change the order or remove relevant entries.