toddhutch Posted October 1, 2023 Posted October 1, 2023 (edited) Everything was working great until early September when MyQ stopped working for Ployglot v2, so I bought the eisy. The migration was frustrating as all heck. Getting the local access using a PC was way less frustrating then the mobile app. The big missing piece was -- default login info for local eisy is admin admin. I purchased the 12.95 subscription from @Goose66, and thank you for your work on this. I think that I went wrong when I said upgrade the polyglot slot, which was the only slot 3. I didn't want to have to go in and redo program references so I hoped it would work. It looked like it didn't but there is an error when it tries to log in. See log below, removed password and email. 2023-10-01 13:20:49,504 MainThread udi_interface INFO polylogger:set_basic_config: set_basic_config: enable=True level=30 2023-10-01 13:20:49,504 MainThread udi_interface INFO __init__:<module>: UDI interface initializing 2023-10-01 13:20:49,504 MainThread udi_interface INFO __init__:<module>: User=0021b9026703_3 2023-10-01 13:20:49,504 MainThread udi_interface INFO __init__:<module>: Home=/var/polyglot/pg3/ns/0021b9026703_3 2023-10-01 13:20:49,505 MainThread udi_interface INFO __init__:<module>: Node Server Path=/var/polyglot/pg3/ns/0021b9026703_3 2023-10-01 13:20:49,505 MainThread udi_interface INFO __init__:<module>: PG3INIT=eyJ1dWlkIjoiMDA6MjE6Yjk6MDI6Njc6MDMiLCJwcm9maWxlTnVtIjozLCJsb2dMZXZlbCI6IkRFQlVHIiwidG9rZW4iOiJySVQ5UEkhPUwxKk5PV0VIIiwibXF0dEhvc3QiOiJsb2NhbGhvc3QiLCJtcXR0UG9ydCI6ODg4Mywic2VjdXJlIjoxLCJpc1BHM3giOnRydWUsInBnM1ZlcnNpb24iOiIzLjIuOCIsImlzeVZlcnNpb24iOiI1LjcuMCIsImVkaXRpb24iOiJGcmVlIn0= 2023-10-01 13:20:49,505 MainThread udi_interface INFO __init__:<module>: Loading interface module 2023-10-01 13:20:49,558 MainThread udi_interface INFO interface:<module>: Loading MQTT module 2023-10-01 13:20:49,997 MainThread udi_interface INFO interface:<module>: MQTT module loaded 2023-10-01 13:20:50,211 MainThread udi_interface INFO __init__:<module>: Loading udi_interface module 2023-10-01 13:20:50,211 MainThread udi_interface INFO __init__:<module>: Loading node module 2023-10-01 13:20:50,211 MainThread udi_interface INFO __init__:<module>: Loading custom module 2023-10-01 13:20:50,212 MainThread udi_interface INFO __init__:<module>: Loading isy module 2023-10-01 13:20:50,212 MainThread udi_interface INFO __init__:<module>: UDI interface initialized 2023-10-01 13:20:50,212 MainThread udi_interface INFO __init__:<module>: UDI Python Interface for Polyglot version 3 3.2.2 Starting... 2023-10-01 13:20:50,243 MainThread udi_interface.interface INFO interface:__init__: Initialization received from Polyglot V3 3.2.8 [ISY: 5.7.0, Slot: 3] 2023-10-01 13:20:50,243 MainThread udi_interface.interface INFO interface:__init__: Connect: Network Interface: {'addr': '192.168.111.229', 'netmask': '255.255.255.0', 'broadcast': '192.168.111.255'} 2023-10-01 13:20:50,244 MainThread udi_interface INFO myqns:run: Starting MyQ node server... 2023-10-01 13:20:50,244 Interface udi_interface.interface INFO interface:_startMqtt: Connecting to MQTT... localhost:8883 2023-10-01 13:20:50,244 MainThread udi_interface.interface WARNING interface:_get_server_data: get_server_data: failed to read file server.json: [Errno 2] No such file or directory: 'server.json' 2023-10-01 13:20:50,245 Interface udi_interface.interface INFO interface:_startMqtt: Using SSL cert: 0021b9026703_3.cert key: 0021b9026703_3.key ca: /usr/local/etc/ssl/certs/ud.ca.cert 2023-10-01 13:20:50,245 MainThread udi_interface.interface WARNING interface:send: MQTT Send waiting on connection :: {'config': {'version': '3.2.22', 'requestId': False}} 2023-10-01 13:20:50,295 MQTT udi_interface.interface INFO interface:_connect: MQTT Connected with result code 0 (Success) 2023-10-01 13:20:50,295 MQTT udi_interface.interface INFO interface:_connect: MQTT Subscribing to topic: udi/pg3/ns/clients/00:21:b9:02:67:03_3 - MID: 2 Result: 0 2023-10-01 13:20:50,338 MQTT udi_interface.interface INFO interface:_subscribe: MQTT Subscribed Succesfully for Message ID: 2 - QoS: (0,) 2023-10-01 13:20:53,264 MainThread udi_interface.interface INFO interface:updateProfile: Sending Install Profile command to Polyglot. 2023-10-01 13:20:53,290 MQTT udi_interface.interface DEBUG interface:_message: QUEUING incoming message getAll 2023-10-01 13:20:53,290 Command udi_interface.interface DEBUG interface:_parseInput: DEQUEING getAll 2023-10-01 13:20:53,290 Thread-2 udi_interface.custom DEBUG custom:load: CUSTOM: load {'username': '########@gmail.com', 'password': '##################'} 2023-10-01 13:20:53,290 Command udi_interface.custom DEBUG custom:load: CUSTOM: load {'login_error': 'There was an error connecting to the MyQ service. Please check the log files and correct the issue before restarting the nodeserver.'} 2023-10-01 13:20:53,291 Thread-2 udi_interface.custom DEBUG custom:load: CUSTOM: -- checking username / ########@gmail.com 2023-10-01 13:20:53,291 Command udi_interface.custom DEBUG custom:load: CUSTOM: -- checking login_error / There was an error connecting to the MyQ service. Please check the log files and correct the issue before restarting the nodeserver. 2023-10-01 13:20:53,291 Thread-2 udi_interface.custom DEBUG custom:load: CUSTOM: -- checking password / ################## 2023-10-01 13:20:53,291 Command udi_interface.interface DEBUG interface:_handleInput: Key nsdata should be passed to node server. 2023-10-01 13:20:53,292 Command udi_interface.interface DEBUG interface:_handleInput: Key oauth should be passed to node server. 2023-10-01 13:20:53,292 Thread-7 udi_interface DEBUG myqns:start: In Nodeserver start()... 2023-10-01 13:20:53,293 Thread-7 udi_interface.custom DEBUG custom:clear: CUSTOM: Clear ...saving 2023-10-01 13:20:53,293 Thread-7 udi_interface.custom INFO custom:_save: Sending data notices to Polyglot. 2023-10-01 13:20:53,293 Thread-7 udi_interface.interface DEBUG interface:send: PUBLISHING {'set': [{'key': 'notices', 'value': {}}]} 2023-10-01 13:20:53,293 Thread-7 udi_interface.node DEBUG node:_updateDrivers: Update service default GPV to 1 / 25 2023-10-01 13:20:53,294 Thread-7 udi_interface.node DEBUG node:_updateDrivers: Update service default ST to 0 / 2 2023-10-01 13:20:53,294 Thread-7 udi_interface.custom DEBUG custom:__init__: CUSTOM: Initialzing _rawdata to empty 2023-10-01 13:20:53,294 Thread-7 udi_interface.interface INFO interface:addNode: Adding node MyQ Service(service) [None] 2023-10-01 13:20:53,294 Thread-7 udi_interface.interface DEBUG interface:send: PUBLISHING {'addnode': [{'address': 'service', 'name': 'MyQ Service', 'nodeDefId': 'SERVICE', 'primaryNode': 'service', 'drivers': [{'driver': 'ST', 'value': 0, 'uom': 2}, {'driver': 'GPV', 'value': '1', 'uom': 25}], 'hint': [0, 0, 0, 0], 'private': None, 'rename': False}]} 2023-10-01 13:20:53,294 MQTT udi_interface.interface DEBUG interface:_message: QUEUING incoming message getNsInfo 2023-10-01 13:20:53,295 Thread-7 udi_interface.interface INFO interface:setController: Using node "service", driver "GPV" for connection status. 2023-10-01 13:20:53,295 Command udi_interface.interface DEBUG interface:_parseInput: DEQUEING getNsInfo 2023-10-01 13:20:53,295 Thread-7 udi_interface.interface DEBUG interface:send: PUBLISHING {'setController': {'node': 'service', 'driver': 'GPV'}} 2023-10-01 13:20:53,314 MQTT udi_interface.interface INFO interface:_message: custom data response {'customparamsdoc': '<h2>MyQ NodeServer Configuration</h2>\n\n<p>Add the required Custom Configuration Parameters for "username" and "password" below for your MyQ account. Note that the node server won\'t work with accounts tied to an Amazon, Google, or Apple login -- you must have a MyQ account. Once the "MyQ Service" appears in the Admin Console, click the "Discover Devices" button for the node to discover MyQ bridges (hubs) and devices linked to your account. If your account has devices linked for different homes, enter the "homename" Custom Configuration Parameter below to specify which home to load devices for.</p>\n\n<h4>Advanced Configuration:</h4>\n\n<ul>\n<li>key: shortPoll, value: polling interval for MyQ cloud service in "active" polling mode (defaults to 20 seconds - minimum polling interval).</li>\n<li>key: longPoll, value: polling interval for MyQ cloud service when not in "active" polling mode (defaults to 60 seconds).</li>\n</ul>\n\n<h4>Custom Configuration Parameters:</h4>\n\n<ul>\n<li>key: username, value: username (email address) for MyQ online account (required)</li>\n<li>key: password, value: password for MyQ online account (required)</li>\n<li>key: homename, value: home name from which to load devices (if your account has access to multiple homes) (optional)</li>\n</ul>\n'} 2023-10-01 13:20:53,316 MQTT udi_interface.interface INFO interface:_message: Successfully set key = customparamsdoc 2023-10-01 13:20:53,357 MQTT udi_interface.interface DEBUG interface:_message: QUEUING incoming message notices 2023-10-01 13:20:53,357 Command udi_interface.interface DEBUG interface:_parseInput: DEQUEING notices 2023-10-01 13:20:53,358 MQTT udi_interface.interface INFO interface:_message: Successfully set key = notices 2023-10-01 13:20:53,358 Command udi_interface.custom DEBUG custom:load: CUSTOM: load {} 2023-10-01 13:20:53,398 MQTT udi_interface.interface DEBUG interface:_message: QUEUING incoming message setController 2023-10-01 13:20:53,398 Command udi_interface.interface DEBUG interface:_parseInput: DEQUEING setController 2023-10-01 13:20:53,398 Command udi_interface.interface DEBUG interface:_handleInput: connection status node/driver update 2023-10-01 13:20:53,458 MQTT udi_interface.interface INFO interface:_message: Profile installation finished 2023-10-01 13:20:53,500 MQTT udi_interface.interface DEBUG interface:_message: QUEUING incoming message addnode 2023-10-01 13:20:53,500 Command udi_interface.interface DEBUG interface:_parseInput: DEQUEING addnode 2023-10-01 13:20:53,501 Thread-9 udi_interface DEBUG nodes:start: In start() for MyQ Service node... 2023-10-01 13:20:53,501 Command udi_interface.interface DEBUG interface:_handleResult: add node response: {'id': '47acc836-0694-40dd-b73b-3eb40da72c1f', 'uuid': '00:21:b9:02:67:03', 'profileNum': 3, 'address': 'service', 'name': 'MyQ Service', 'nodeDefId': 'SERVICE', 'nls': None, 'hint': '0x00000000', 'controller': 1, 'primaryNode': 'service', 'private': None, 'isPrimary': 1, 'enabled': 1, 'timeAdded': 1696188718719, 'timeModified': 1696191653347, 'dbVersion': 1} 2023-10-01 13:20:53,501 Thread-9 udi_interface INFO nodes:start: Establishing initial MyQ connection... 2023-10-01 13:20:53,501 Thread-9 udi_interface DEBUG myqapi:loginToService: in API loginToService()... 2023-10-01 13:20:53,502 Thread-9 udi_interface INFO myqapi:_oAuthRetrieveToken: Logging in and retrieving access token via oAuth... 2023-10-01 13:20:53,574 Thread-9 udi_interface WARNING myqapi:_oAuthRequest: Network/server error logging into MyQ service: 429 Client Error: Too Many Requests for url: https://partner-identity.myq-cloud.com/connect/authorize?client_id=IOS_CGI_MYQ&code_challenge=FCziqTLLAGz_Gdngx19K61LAt6tSyAwDVDfsK-Qp250&code_challenge_method=S256&redirect_uri=com.myqops%3A%2F%2Fios&response_type=code&scope=MyQ_Residential+offline_access 2023-10-01 13:20:53,574 Thread-9 udi_interface DEBUG myqapi:_oAuthRetrieveToken: Error in Step 1 of oAuth flow. 2023-10-01 13:20:53,574 Thread-9 udi_interface.custom DEBUG custom:__setitem__: CUSTOM: login_error = There was an error connecting to the MyQ service. Please check the log files and correct the issue before restarting the nodeserver. ...saving 2023-10-01 13:20:53,574 Thread-9 udi_interface.custom INFO custom:_save: Sending data notices to Polyglot. 2023-10-01 13:20:53,574 Thread-9 udi_interface.interface DEBUG interface:send: PUBLISHING {'set': [{'key': 'notices', 'value': {'login_error': 'There was an error connecting to the MyQ service. Please check the log files and correct the issue before restarting the nodeserver.'}}]} 2023-10-01 13:20:53,576 Thread-9 udi_interface.node DEBUG node:setDriver: service:MyQ Service No change in ST's value 2023-10-01 13:20:53,593 MQTT udi_interface.interface DEBUG interface:_message: QUEUING incoming message notices 2023-10-01 13:20:53,593 Command udi_interface.interface DEBUG interface:_parseInput: DEQUEING notices 2023-10-01 13:20:53,594 Command udi_interface.custom DEBUG custom:load: CUSTOM: load {'login_error': 'There was an error connecting to the MyQ service. Please check the log files and correct the issue before restarting the nodeserver.'} 2023-10-01 13:20:53,594 Command udi_interface.custom DEBUG custom:load: CUSTOM: -- checking login_error / There was an error connecting to the MyQ service. Please check the log files and correct the issue before restarting the nodeserver. 2023-10-01 13:20:53,635 MQTT udi_interface.interface INFO interface:_message: Successfully set key = notices I've stopped it an maybe it will work in a while, but I'm thinking this might be something to do with the agent not being updated since I used the same node, and it's not unique to me. 👍👍 Edited October 1, 2023 by toddhutch
Goose66 Posted October 1, 2023 Posted October 1, 2023 The previous error dealing with UserAgent was an HTTP 403 error, I believe. You're getting a 429 Client Error: Too Many Requests. I will have to look into it. In the meantime, what's your shortPoll and longPoll set to in your Advanced Configuration?
Goose66 Posted October 2, 2023 Posted October 2, 2023 (edited) I checked my log files under PG3x since my migration last week. I got the same 429 - Too many requests error back on 9/26 on every longpoll oAuth token refresh for approx. 3 hours around 1:00am and again on 9/29 for a similar timeframe. Otherwise the MyQ node server has run fine since the migration. At this point, it looks like it's a transient error having something to do with the partner Chamberlain is using for oAuth authentication. I don't see anything about it in the Issues for the pymyq library (from which the node server was patterned). If a bunch of people start getting it all the time, I will look into it further. Edited October 2, 2023 by Goose66
toddhutch Posted October 2, 2023 Author Posted October 2, 2023 @Goose66 I left the short and long default, I just started the service, and it worked perfectly. I think it was probably because I had the polyglot v2 running up until minutes before I did this. All good! 1
Goose66 Posted October 2, 2023 Posted October 2, 2023 (edited) Excellent. I will try to keep an eye on it. I may need to back off on the frequency it tries to refresh the token on initial failure. It may just be a simple longPoll change, or it may need its own period setting. Edited October 2, 2023 by Goose66
Goose66 Posted October 2, 2023 Posted October 2, 2023 Here's what the two instances I mentioned above look like: It gets an initial error in oAuth, e.g. a 401 error (not uncommon). It retries every minute (longPoll interval) for 6 or 7 minutes, then the server starts responding with the 429 - Too many requests error. So I think I need a longer retry on failure than the longPoll interval, or maybe after some number of failure retries, I crank down the frequency of retries. I'll put a TODO in the code for the next version.
Goose66 Posted October 9, 2023 Posted October 9, 2023 The 429 error is starting to crop up in other circles. Evidently there is a header included in these that specify how long you need to wait before retrying and the numbers are like 30 minutes or more, so I may need to rework the retry logic to find and start using this number on the retry. Note again this seems to be somewhat limited to when the node server is restarted and it has to acquire a whole new oAuth token for access.
Recommended Posts