I figured why my bridge wasn’t connecting or why it would connect and flap.
I’m one of the few that have over 5 MyQ items (1 GDO, 5 lamp units and 7 switches)
Once I have 5 or more items added to my account the bridge becomes unstable. Once all items are added it won’t connect at all.
I can provide logs. I had debug turned on but I couldn’t see anything obvious. All I could gather was it didn’t really like it when it was getting the list of items but I couldn’t see the error message just that was retrying and that’s what lead me to remove items from my accounts to test.
My bridge operation has been incredibly spotty. I’ll download the daily build, get the bundles operating and all seems fine, then again this morning I’m back to the same “ERROR:COMM” status on my bridge thing.
The log error however is down to a single line now:
Unsure what his happening to make the binding so continuously unstable? Is it something Chamberain is doing on their end?
***update: And now, as soon as I type this and hit save, the thing is working again, then off again?!?
This from the DEBUG files:
2021-09-19 09:38:30.451 [DEBUG] [q.internal.handler.MyQAccountHandler] - MyQ communication error
org.openhab.binding.myq.internal.handler.MyQAccountHandler$MyQCommunicationException: Invalid Response Code 0 :
at org.openhab.binding.myq.internal.handler.MyQAccountHandler.parseResultAndUpdateStatus(MyQAccountHandler.java:435) ~[?:?]
at org.openhab.binding.myq.internal.handler.MyQAccountHandler.getDevices(MyQAccountHandler.java:349) ~[?:?]
at org.openhab.binding.myq.internal.handler.MyQAccountHandler.fetchData(MyQAccountHandler.java:271) ~[?:?]
at org.openhab.binding.myq.internal.handler.MyQAccountHandler.normalPoll(MyQAccountHandler.java:259) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:829) [?:?]
I’m having a similar problem.
It gets increasingly unstable the more items I have on my MyQ account, even if I don’t add them as things.
My debug shows something similar.
@digitaldan
EDIT:
Did some more testing.
Basically I can’t have more than 4 MyQ devices added to the account or the binding will fail to connect or refresh the token.
Hmm, an http response should never be 0, thats very odd, I’m not sure how that can be, i would think the Jetty HTTP client would not even allow that. I’ll take a look and see if my logs show something similar.
Since it’s a general communication error, we only mark the binding offline, but will still continue to try and poll every 60 seconds ( or lower if configured) , so it sounds like the next poll worked. It would be helpful to know from your logs the pattern of off and online. I guess its possible this is MyQ throttling requests, but again the 0 response code is suspicious.
So we don’t poll any differently due to number of devices, nor does the number devices have anything to do with the token. I’m not sure how yet that would cause issues.
It would be helpful to have debug logs (and possibly trace as well) as this does not sound like the other issue yet. Also can you let me know how you have this configured (through the UI or thing files)?
Everything is done in UI. I’m starting from scratch trying to redesign everything on the new OH3 Paradigm. Trying to do away with the cfg files.
I have a tracelog where the binding is the only one running. In the process I started 4 MyQ items on my Account. Then I added a 5th and during the next refresh for a token the Bridge fails to the error below.
I then remove the 5th item from my account without making any changes to OH3 and during the next refresh it get the token and it’s working fine.
Please PM it to me. I’m still not sure that the number of things or items is really at play, or if its just a coincidence, there is no relationship to items and the logic of this binding that would cause that afaik.
That error has nothing todo with getting a token, its being thrown trying to the general device API.
Thanks, thats all normal, and your MyQ things should be online. What i was hoping is if you could send logs when it fails. But actually, i can see this in my logs too. It seems to have happened a few times starting on the 14th (see logs below)
If it does happen, and stays offline for more than a min (so does not come back on the next poll), please PM me the relevant logs. I’ll see about catching this error specifically and recovering from it quicker in the mean time. It has not happened today, so this seems fairly random on my system.
2021-09-09 20:36:56.043 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 :
2021-09-09 20:37:26.284 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 : to ONLINE
2021-09-14 23:40:10.660 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 503 : <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
2021-09-14 23:40:41.121 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 503 : <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
2021-09-15 22:04:29.399 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 :
2021-09-15 22:04:59.696 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 : to ONLINE
2021-09-16 02:10:32.678 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 503 : <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
2021-09-16 02:11:12.679 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 503 : <!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.01//EN""http://www.w3.org/TR/html4/strict.dtd">
2021-09-16 02:15:03.132 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 : to ONLINE
2021-09-16 02:16:14.471 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 :
2021-09-16 02:18:04.855 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 : to ONLINE
2021-09-16 02:19:14.978 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 :
2021-09-16 02:20:25.366 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 : to ONLINE
2021-09-16 02:21:05.368 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 :
2021-09-16 02:22:55.591 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'myq:account:home' changed from OFFLINE (COMMUNICATION_ERROR): Invalid Response Code 0 : to ONLINE
I believe you need to re-install the add-on per instructions above after upgrading, until it is merged with the code release code. I could be wrong about this, but reinstalling the the jar worked for me.
I’m assuming you mean the 3.2 snapshot build and not milestone? Can you post the build version? If it is the snapshot build, can you try pausing and starting the account thing from the UI and see if that helps? that will cause a new token to be requested. It sounds like there is an issue getting the token, which is odd since i would expect the error to happen earlier in the login process, and this error happens after that.
The code has been merged and is available in the 3.2 snapshot distribution.
No, there is a MyQ binding, but does not have the changes discussed here. See this post for the jar location, and scroll up a bit for instructions on how to install, or use the SNAPSHOT distro which has the right one already.
Ok, I installed the 3.2 snapshot with the dependancy. I manage to connect my account, was online, I created my garage door thing. The account jump a lot from online to COMMUNICATION_ERROR Invalid Response Code 0 or 1 and I have no status on the door (while it says online when both or online, else error_bridge)
My Guess and it’s a blind guess is Chamberlain has some kind of rate limiting going on.
It was encountered as far back as API v4. When the API would lock out accounts in a cooldown when a “Rapid poll” was executed and the account had more than 2 or 3 devices.
Can you tell me a detailed account of how you created your account and door things ? Also are you saying you get both a 0 and 1 response code? Can you copy the exact message please as 1 is not something yet seen. I just tried doing this in the UI (add account thing, go to inbox, scan, add all 3 newly discovered myq things, etc…) can’t seem to reproduce this.
I don’t think thats the case, for one i would expect a real response code, I have never seen 0 with any service since the dawn of time, and i’m not 100% certain its coming from MyQ. 0 is not a RFC allowed code, and modern web frameworks would make it difficult to use. I would expect a 429 error (too many requests) or any 4xx error, maybe even a 5xx error. Also i just tried opening and closing my garage door multiple times as well as closing multiple of them together (which should not make any difference, we only poll once for all of them) which triggered our rapid polling for over a minute ( we poll every 5 seconds for rapid) and did not get an error. If i can get it to happen regularly i can debug at our HTTP client level, but so far i can’t make it happen at will.
So a couple of updates. After lurking around other projects, it sounds like MyQ cloud ops has had a rough month stability wise and has been very flaky. The incidents in my logs line up with issues they had with their service that other projects also noted. I don’t think thats the whole issue, but obviously it looks very similar from our clients POV.
I’m going to assume this 0 response code is a bug in Jetty and that what we are seeing is the MyQ service prematurely closing our connection. Normally this is catchable, but jetty is not throwing it, and so the response code never gets set (and in java a unset int is 0). I think this happens both when MyQ may decide it doesn’t like your user agent anymore and when their service is randomly crashing. I have added a quick retry logic which both changes the useragent and then tries again to poll. We also generate a new useragent if we have to do a full login again.
You can find the jar on my repo , if you use the cli to update the current SNAPSHOT binding like: bundle:update org.openhab.binding.myq file:////some/path/org.openhab.binding.myq-3.2.0-SNAPSHOT.jar then you do not have to install jsoup (its already installed) , if you drop it in your addons folder, but have to uninstall the current one first, then you will need to install jsoup again.
I’m not that confident this will fix the issue here as i can’t seem to reproduce them, but lets see how it goes.
Can you try following the instructions i posted in this thread to let the binding discover the devices automatically? See Chamberlain MyQ Binding - #745 by digitaldan . If that works, can you confirm if the serial number you have is the same that gets discovered?
