Virtual Shade driver is almost useless

Since I cannot create groups of blinds, I created a virtual blinds device using the "Virtual Shade" driver. I then created open/close rules for when that device is opened or closed from a dashboard or Alexa.

Does anyone else find it to be very delayed in response to commands under the best of times, and completely unresponsive at all other times? Because that has been my experience.

I'm only using it because I cannot include blinds in groups.

Is there a better way to do this?

Commands execute nearly instantly for me. What I suspect you're noticing is that they simulate "real" shade behavior: running a close() command changes the shade first to "closing," then to "closed"--not immediately to "closed" (as you might expect from, say, a virtual switch driver that immediately sets the "switch" attribute to "off" with an off() command). You might be able to avoid this instead by triggering your rules on "opening" or "closing" or whatever events you really see in your case instead of the final state (or both), the exact means of which will vary depending on what you have set up and what your real devices do.

Regarding groups and scenes, blinds are an unfortunate omission. There might be a community app that can group them, but I'm not aware of one off the top of my head. Some blinds/shades support dimmer-esque capabilities (these being commands like setLevel()), and in that case, you should be able to use then in a normal, dimmer-type group. (The default group device is an RGBW bulb, which may pose issues for voice assistants or be surprising in some apps; even this might, too, but it's workable for me.) However, not all drivers support this--most newer ones I've seen are "pure" shade/blind drivers, with others presumably exposing both capabilities so as to be compatible with a wider variety of apps (before these were more common, not that they really are).

1 Like

I just changed the transition time to "ASAP." Nevertheless, this is what I'm noticing.

I tell Alexa to open the blinds (through the virtual shade device). She does so immediately. Then i tell her to close the blinds. She dings acknowledgement. But nothing happens. And I wait. And still nothing happens. And I wait, and wait, and wait.....

I'm not sure if what you are suggesting explains this problem.

This would be easy to narrow down with a few different actions, depending on what you find in some of these places:

  • take a look at the device page for the virtual device, and see if "Current States" accurately reflects what you thin these attributes should after a command from Alexa
  • to rule out an Alexa problem (that cloud could easily be the source of some delay), see if manually sending the same commands from the device page works as you expect--things like "open," "close," or "set position"
  • it sounds like you're using a rule to tie this all together, so turning on "Trigger" and "Action" logging there (at least) may show you what the rule thinks it's doing and when
  • you can also try enabling debug logging on your blinds/shades to see if this shows when they actually have commands run on them; not all drivers do this, but many of Hubitat's newer drivers do, so your luck may vary
    • if your real devices show that they were issued commands and were slow to respond, you've narrowed the issue down to a device or possibly network issue
    • if individual devices work fine from their page, it could still be a network issue--flooding your network with lots of commands around the same time--and spacing the commands out a bit may help (adding a couple hundred milliseconds of delay, or whatever RM lets you do, which might be 1 second minimum)
    • note that debug logging will also show when information is received back from the real blinds about their current states before the "raw"-ish Z-Wave (or whatever) data gets parsed into an event on Hubitat, but that is unlikely to be of use here
1 Like

Just to clarify, the problem is occurring regardless of whether I use Alexa or the dashboard button, but I'll go through some of these and report back my findings.

Thanks!

1 Like

Also logs are your friends

I use the virtual shades to trigger my Leviosa shades through a bond hub and it works pretty well for me.

I use Alexa and the dashboard, but mostly Alexa to control them. The main issue I have with the Virtual shades and Alexa is if I tell Alexa to raise or lower the shade she always reports back something went wrong. The actual shade does as it should but she always reports that message. When you say open or close it works fine.

To get around it I created routines in Alexa, so when I say raise or lower it runs a routine that sets a position on the virtual shade and if it does it in the Alexa app routine it doesn't give an error message. I wish they could fix that as I have to have a raise and lower Alexa routine for every shade.

I have never noticed significant delay between when I tell Alexa to control a shade and the time the virtual shade reacts. There is delay from the time I say the command and the actual shade moves. But it's not bad. From the time I tell Alexa to change a shade and the time the actual shade reacts is about +/-5 seconds.

I have a routine where I can say raise or lower a shade without specifying and it will open the shade in the room I am in. That takes about 15 to 20 seconds.

In my rules for the shades I trigger on the virtual shade opening or closing. So I have to use the minimum open and close delay of 5 seconds. After my RM rule triggers on opening or closing, it waits for the shade to change states. It will change to partially open, closed or open. If it changes to open or closed then you send a open or close command to the actual shade, if it is partially open then if the trigger was opening that means it was raised if the trigger was closing then it was lowered.

I have all my shades set with three positions fully open or closed and I have one setpoint in the middle. So with my RM rule and a set of global variables I can keep track of what position the shades are in. Now if someone uses one of the remotes for the shade then it no longer knows where the shade is positioned. We never use the remotes though, unless the internet is down.

First for reference, here are the rules I have to work with "Master Bedroom Blinds" which is a virtual shade device to control three different blinds motors - Master Bedroom Blinds 1, Master Bedroom Blinds 2, and Master Bedroom Blinds 3. I checked the triggers you suggested, and I'm putting the rules here just in case anyone can spot anything obviously wrong.

I'm also including a screen shot of the virtual shade device page:

Here is what happened when I told Alexa "open Master Bedroom blinds."

The blinds did in fact open, and position says 100 and window shade: says "open" in the device page.

dev:20862021-08-17 09:28:38.526 pm traceupdateWindowShadeOpening

dev:20862021-08-17 09:28:38.523 pm debugparse: opening

dev:20862021-08-17 09:28:38.519 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00000104000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 01, 04, 00, 01, 00]]

dev:20862021-08-17 09:28:38.491 pm tracecheckHeartbeat: waitMillis=3999998

dev:20862021-08-17 09:28:38.487 pm debugupdatePresence: present=true

dev:20862021-08-17 09:28:38.398 pm traceisWithinOne: position=100, lastPosition=100

dev:20862021-08-17 09:28:38.395 pm debugupdatePosition: position=100

dev:20862021-08-17 09:28:38.392 pm debugupdateWindowShadeArrived: position=100

dev:20862021-08-17 09:28:38.389 pm debugparse: arrived at position 100

dev:20862021-08-17 09:28:38.385 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00000302000400000064, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 03, 02, 00, 04, 00, 00, 00, 64]]

dev:20862021-08-17 09:28:38.353 pm tracecheckHeartbeat: waitMillis=3999997

dev:20862021-08-17 09:28:38.349 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:38.217 pm traceupdateWindowShadeOpening

dev:20872021-08-17 09:28:38.214 pm debugparse: opening

dev:20872021-08-17 09:28:38.206 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00000104000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 01, 04, 00, 01, 00]]

dev:20872021-08-17 09:28:38.178 pm tracecheckHeartbeat: waitMillis=3999997

dev:20872021-08-17 09:28:38.174 pm debugupdatePresence: present=true

dev:20892021-08-17 09:28:38.106 pm traceupdateWindowShadeOpening

dev:20892021-08-17 09:28:38.103 pm debugparse: opening

dev:20892021-08-17 09:28:38.099 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00000104000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 01, 04, 00, 01, 00]]

dev:20872021-08-17 09:28:38.080 pm traceisWithinOne: position=100, lastPosition=100

dev:20872021-08-17 09:28:38.077 pm debugupdatePosition: position=100

dev:20872021-08-17 09:28:38.074 pm debugupdateWindowShadeArrived: position=100

dev:20872021-08-17 09:28:38.071 pm debugparse: arrived at position 100

dev:20872021-08-17 09:28:38.067 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00000302000400000064, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 03, 02, 00, 04, 00, 00, 00, 64]]

dev:20892021-08-17 09:28:38.059 pm tracecheckHeartbeat: waitMillis=3999998

dev:20892021-08-17 09:28:38.051 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:38.036 pm tracecheckHeartbeat: waitMillis=3999997

dev:20872021-08-17 09:28:38.032 pm debugupdatePresence: present=true

dev:20892021-08-17 09:28:37.960 pm traceisWithinOne: position=100, lastPosition=100

dev:20892021-08-17 09:28:37.957 pm debugupdatePosition: position=100

dev:20892021-08-17 09:28:37.954 pm debugupdateWindowShadeArrived: position=100

dev:20892021-08-17 09:28:37.950 pm debugparse: arrived at position 100

dev:20892021-08-17 09:28:37.947 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00000302000400000064, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 03, 02, 00, 04, 00, 00, 00, 64]]

dev:20892021-08-17 09:28:37.918 pm tracecheckHeartbeat: waitMillis=3999998

dev:20892021-08-17 09:28:37.914 pm debugupdatePresence: present=true

dev:20862021-08-17 09:28:34.841 pm debugupdateSpeed: speed=40

dev:20862021-08-17 09:28:34.836 pm debugparse: speed=40

dev:20862021-08-17 09:28:34.833 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00006902000400000028, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 69, 02, 00, 04, 00, 00, 00, 28]]

dev:20862021-08-17 09:28:34.803 pm tracecheckHeartbeat: waitMillis=3999997

dev:20862021-08-17 09:28:34.799 pm debugupdatePresence: present=true

dev:20862021-08-17 09:28:34.713 pm traceupdateWindowShadeClosing

dev:20862021-08-17 09:28:34.710 pm debugparse: closing

dev:20862021-08-17 09:28:34.703 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00000104000102, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 01, 04, 00, 01, 02]]

dev:20862021-08-17 09:28:34.675 pm tracecheckHeartbeat: waitMillis=3999998

dev:20862021-08-17 09:28:34.671 pm debugupdatePresence: present=true

dev:20862021-08-17 09:28:34.572 pm traceisWithinOne: position=100, lastPosition=100

dev:20862021-08-17 09:28:34.569 pm debugupdatePosition: position=100

dev:20862021-08-17 09:28:34.566 pm debugupdateWindowShadeMoving: position=100, lastPosition=100

dev:20862021-08-17 09:28:34.563 pm debugparse: moving to position 100

dev:20862021-08-17 09:28:34.559 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00000202000400000064, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 02, 02, 00, 04, 00, 00, 00, 64]]

dev:20862021-08-17 09:28:34.530 pm tracecheckHeartbeat: waitMillis=3999997

dev:20862021-08-17 09:28:34.526 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:34.470 pm debugupdateSpeed: speed=40

dev:20872021-08-17 09:28:34.467 pm debugparse: speed=40

dev:20872021-08-17 09:28:34.457 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00006902000400000028, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 69, 02, 00, 04, 00, 00, 00, 28]]

dev:20862021-08-17 09:28:34.430 pm traceparse: ACK command=0

dev:20872021-08-17 09:28:34.426 pm tracecheckHeartbeat: waitMillis=3999998

dev:20872021-08-17 09:28:34.423 pm debugupdatePresence: present=true

dev:20862021-08-17 09:28:34.400 pm tracecheckHeartbeat: waitMillis=3999995

dev:20862021-08-17 09:28:34.394 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:34.360 pm traceupdateWindowShadeClosing

dev:20872021-08-17 09:28:34.357 pm debugparse: closing

dev:20872021-08-17 09:28:34.354 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00000104000102, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 01, 04, 00, 01, 02]]

dev:20872021-08-17 09:28:34.294 pm tracecheckHeartbeat: waitMillis=3999998

dev:20872021-08-17 09:28:34.289 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:34.095 pm traceisWithinOne: position=100, lastPosition=100

dev:20872021-08-17 09:28:34.092 pm debugupdatePosition: position=100

dev:20872021-08-17 09:28:34.089 pm debugupdateWindowShadeMoving: position=100, lastPosition=100

dev:20872021-08-17 09:28:34.086 pm debugparse: moving to position 100

dev:20872021-08-17 09:28:34.082 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00000202000400000064, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 02, 02, 00, 04, 00, 00, 00, 64]]

dev:20872021-08-17 09:28:34.051 pm tracecheckHeartbeat: waitMillis=3999998

dev:20872021-08-17 09:28:34.047 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:34.015 pm traceparse: ACK command=0

dev:20872021-08-17 09:28:33.986 pm tracecheckHeartbeat: waitMillis=3999997

dev:20872021-08-17 09:28:33.982 pm debugupdatePresence: present=true

dev:20892021-08-17 09:28:33.873 pm debugupdateSpeed: speed=40

dev:20892021-08-17 09:28:33.869 pm debugparse: speed=40

dev:20892021-08-17 09:28:33.866 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00006902000400000028, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 69, 02, 00, 04, 00, 00, 00, 28]]

dev:20892021-08-17 09:28:33.835 pm tracecheckHeartbeat: waitMillis=3999998

dev:20892021-08-17 09:28:33.831 pm debugupdatePresence: present=true

dev:20892021-08-17 09:28:33.749 pm traceupdateWindowShadeClosing

dev:20892021-08-17 09:28:33.746 pm debugparse: closing

dev:20892021-08-17 09:28:33.742 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00000104000102, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 01, 04, 00, 01, 02]]

dev:20892021-08-17 09:28:33.711 pm tracecheckHeartbeat: waitMillis=3999997

dev:20892021-08-17 09:28:33.707 pm debugupdatePresence: present=true

dev:20892021-08-17 09:28:33.619 pm traceisWithinOne: position=100, lastPosition=100

dev:20892021-08-17 09:28:33.616 pm debugupdatePosition: position=100

dev:20892021-08-17 09:28:33.613 pm debugupdateWindowShadeMoving: position=100, lastPosition=100

dev:20892021-08-17 09:28:33.610 pm debugparse: moving to position 100

dev:20892021-08-17 09:28:33.606 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00000202000400000064, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 02, 02, 00, 04, 00, 00, 00, 64]]

dev:20892021-08-17 09:28:33.571 pm tracecheckHeartbeat: waitMillis=3999997

dev:20892021-08-17 09:28:33.567 pm debugupdatePresence: present=true

dev:20892021-08-17 09:28:33.509 pm traceparse: ACK command=0

dev:20892021-08-17 09:28:33.468 pm tracecheckHeartbeat: waitMillis=3999997

dev:20892021-08-17 09:28:33.462 pm debugupdatePresence: present=true

dev:20872021-08-17 09:28:33.377 pm tracesendTuyaCommand: message=8F9B0202000400000064

dev:20872021-08-17 09:28:33.374 pm tracesendTuyaCommand: dp=0x02, dpType=0x02, fnCmd=0x00000064, fnCmdLength=8

dev:20872021-08-17 09:28:33.368 pm tracecheckForResponse: waitMillis=59994

dev:20872021-08-17 09:28:33.364 pm tracecheckForResponse: waitingForResponseSinceMillis=1629253713352

dev:20872021-08-17 09:28:33.361 pm traceisWithinOne: position=100, lastPosition=0

dev:20872021-08-17 09:28:33.357 pm debugsetPosition: position=100

dev:20872021-08-17 09:28:33.352 pm debugopen

dev:20862021-08-17 09:28:33.342 pm tracesendTuyaCommand: message=813A0202000400000064

dev:20862021-08-17 09:28:33.338 pm tracesendTuyaCommand: dp=0x02, dpType=0x02, fnCmd=0x00000064, fnCmdLength=8

dev:20862021-08-17 09:28:33.324 pm tracecheckForResponse: waitMillis=59996

dev:20862021-08-17 09:28:33.320 pm tracecheckForResponse: waitingForResponseSinceMillis=1629253713303

dev:20862021-08-17 09:28:33.316 pm traceisWithinOne: position=100, lastPosition=0

dev:20862021-08-17 09:28:33.303 pm debugsetPosition: position=100

dev:20862021-08-17 09:28:33.299 pm debugopen

dev:20892021-08-17 09:28:33.277 pm tracesendTuyaCommand: message=D5A90202000400000064

dev:20892021-08-17 09:28:33.274 pm tracesendTuyaCommand: dp=0x02, dpType=0x02, fnCmd=0x00000064, fnCmdLength=8

dev:20892021-08-17 09:28:33.261 pm tracecheckForResponse: waitMillis=59994

dev:20892021-08-17 09:28:33.257 pm tracecheckForResponse: waitingForResponseSinceMillis=1629253713249

dev:20892021-08-17 09:28:33.250 pm traceisWithinOne: position=100, lastPosition=0

dev:20892021-08-17 09:28:33.247 pm debugsetPosition: position=100

dev:20892021-08-17 09:28:33.239 pm debugopen

app:10082021-08-17 09:28:33.186 pm infoMaster Bedroom Blinds Open Triggered

app:10082021-08-17 09:28:33.181 pm infoMaster Bedroom Blinds Open: Master Bedroom Blinds windowShade open

dev:20882021-08-17 09:28:33.050 pm infoMaster Bedroom Blinds was turned on

dev:20882021-08-17 09:28:33.044 pm infoMaster Bedroom Blinds is open

dev:20882021-08-17 09:28:33.037 pm infoMaster Bedroom Blinds was set to 100%

Now here is what happened when I told Alexa "close Master Bedroom Blinds"

The blinds did not close.

However, in the device page for virtual shade driver, it says that the Master Bedroom Blinds are closed and position is zero.

Here are the logs for Master Bedroom Blinds 1:

dev:20862021-08-17 09:16:34.528 pm tracecheckForResponse: waitingForResponseSinceMillis=null

dev:20862021-08-17 09:15:35.542 pm debugupdateDirection: directionText=reverse, directionValue=1

dev:20862021-08-17 09:15:35.541 pm debugparse: direction=reverse

dev:20862021-08-17 09:15:35.538 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00000504000101, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 05, 04, 00, 01, 01]]

dev:20862021-08-17 09:15:35.505 pm tracecheckHeartbeat: waitMillis=3999998

dev:20862021-08-17 09:15:35.501 pm debugupdatePresence: present=true

dev:20862021-08-17 09:15:35.383 pm traceparse: ACK command=0

dev:20862021-08-17 09:15:35.354 pm tracecheckHeartbeat: waitMillis=3999998

dev:20862021-08-17 09:15:35.350 pm debugupdatePresence: present=true

dev:20862021-08-17 09:15:34.546 pm tracesendTuyaCommand: message=73B90504000101

dev:20862021-08-17 09:15:34.544 pm tracesendTuyaCommand: dp=0x05, dpType=0x04, fnCmd=0x01, fnCmdLength=2

dev:20862021-08-17 09:15:34.518 pm tracecheckForResponse: waitMillis=59995

dev:20862021-08-17 09:15:34.516 pm tracecheckForResponse: waitingForResponseSinceMillis=1629252934512

dev:20862021-08-17 09:15:34.511 pm debugsetDirection: directionText=reverse, directionValue=1

dev:20862021-08-17 09:15:34.060 pm debugupdateMode: modeText=tilt, modeValue=0

dev:20862021-08-17 09:15:34.059 pm debugparse: mode=tilt

dev:20862021-08-17 09:15:34.030 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 C5B9 01 00 0000 02 01 00006504000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:C5B9, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 65, 04, 00, 01, 00]]

dev:20862021-08-17 09:15:33.996 pm tracecheckHeartbeat: waitMillis=3999998

dev:20862021-08-17 09:15:33.992 pm debugupdatePresence: present=true

dev:20862021-08-17 09:15:33.862 pm traceparse: ACK command=0

dev:20862021-08-17 09:15:33.834 pm tracecheckHeartbeat: waitMillis=3999998

dev:20862021-08-17 09:15:33.829 pm debugupdatePresence: present=true

dev:20862021-08-17 09:15:33.521 pm tracesendTuyaCommand: message=F7546504000100

dev:20862021-08-17 09:15:33.519 pm tracesendTuyaCommand: dp=0x65, dpType=0x04, fnCmd=0x00, fnCmdLength=2

dev:20862021-08-17 09:15:33.508 pm tracecheckForResponse: waitMillis=59995

dev:20862021-08-17 09:15:33.505 pm tracecheckForResponse: waitingForResponseSinceMillis=1629252933502

dev:20862021-08-17 09:15:33.501 pm debugsetMode: modeText=null, modeValue=0

dev:20862021-08-17 09:15:32.482 pm debugconfigure

Master Bedroom Blinds 2:

dev:20872021-08-17 09:16:57.434 pm tracecheckForResponse: waitingForResponseSinceMillis=null

dev:20872021-08-17 09:15:58.605 pm debugupdateDirection: directionText=reverse, directionValue=1

dev:20872021-08-17 09:15:58.604 pm debugparse: direction=reverse

dev:20872021-08-17 09:15:58.601 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00000504000101, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 05, 04, 00, 01, 01]]

dev:20872021-08-17 09:15:58.570 pm tracecheckHeartbeat: waitMillis=3999997

dev:20872021-08-17 09:15:58.565 pm debugupdatePresence: present=true

dev:20872021-08-17 09:15:58.448 pm traceparse: ACK command=0

dev:20872021-08-17 09:15:58.417 pm tracecheckHeartbeat: waitMillis=3999997

dev:20872021-08-17 09:15:58.412 pm debugupdatePresence: present=true

dev:20872021-08-17 09:15:57.451 pm tracesendTuyaCommand: message=C3030504000101

dev:20872021-08-17 09:15:57.449 pm tracesendTuyaCommand: dp=0x05, dpType=0x04, fnCmd=0x01, fnCmdLength=2

dev:20872021-08-17 09:15:57.424 pm tracecheckForResponse: waitMillis=59995

dev:20872021-08-17 09:15:57.422 pm tracecheckForResponse: waitingForResponseSinceMillis=1629252957419

dev:20872021-08-17 09:15:57.418 pm debugsetDirection: directionText=reverse, directionValue=1

dev:20872021-08-17 09:15:57.103 pm debugupdateMode: modeText=tilt, modeValue=0

dev:20872021-08-17 09:15:57.102 pm debugparse: mode=tilt

dev:20872021-08-17 09:15:57.097 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 4438 01 00 0000 02 01 00006504000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:4438, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 65, 04, 00, 01, 00]]

dev:20872021-08-17 09:15:57.069 pm tracecheckHeartbeat: waitMillis=3999997

dev:20872021-08-17 09:15:57.065 pm debugupdatePresence: present=true

dev:20872021-08-17 09:15:56.967 pm traceparse: ACK command=0

dev:20872021-08-17 09:15:56.939 pm tracecheckHeartbeat: waitMillis=3999998

dev:20872021-08-17 09:15:56.935 pm debugupdatePresence: present=true

dev:20872021-08-17 09:15:56.422 pm tracesendTuyaCommand: message=4F526504000100

dev:20872021-08-17 09:15:56.421 pm tracesendTuyaCommand: dp=0x65, dpType=0x04, fnCmd=0x00, fnCmdLength=2

dev:20872021-08-17 09:15:56.409 pm tracecheckForResponse: waitMillis=59995

dev:20872021-08-17 09:15:56.407 pm tracecheckForResponse: waitingForResponseSinceMillis=1629252956403

dev:20872021-08-17 09:15:56.402 pm debugsetMode: modeText=null, modeValue=0

dev:20872021-08-17 09:15:55.384 pm debugconfigure

and Master Bedroom Blinds 3:

search

dev:20892021-08-17 09:17:19.962 pm tracecheckForResponse: waitingForResponseSinceMillis=null

dev:20892021-08-17 09:16:20.320 pm debugupdateDirection: directionText=forward, directionValue=0

dev:20892021-08-17 09:16:20.319 pm debugparse: direction=forward

dev:20892021-08-17 09:16:20.316 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00000504000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 05, 04, 00, 01, 00]]

dev:20892021-08-17 09:16:20.288 pm tracecheckHeartbeat: waitMillis=3999997

dev:20892021-08-17 09:16:20.283 pm debugupdatePresence: present=true

dev:20892021-08-17 09:16:20.155 pm traceparse: ACK command=0

dev:20892021-08-17 09:16:20.124 pm tracecheckHeartbeat: waitMillis=3999998

dev:20892021-08-17 09:16:20.120 pm debugupdatePresence: present=true

dev:20892021-08-17 09:16:19.977 pm tracesendTuyaCommand: message=7FF70504000100

dev:20892021-08-17 09:16:19.975 pm tracesendTuyaCommand: dp=0x05, dpType=0x04, fnCmd=0x00, fnCmdLength=2

dev:20892021-08-17 09:16:19.953 pm tracecheckForResponse: waitMillis=59995

dev:20892021-08-17 09:16:19.951 pm tracecheckForResponse: waitingForResponseSinceMillis=1629252979947

dev:20892021-08-17 09:16:19.946 pm debugsetDirection: directionText=forward, directionValue=0

dev:20892021-08-17 09:16:19.824 pm debugupdateMode: modeText=tilt, modeValue=0

dev:20892021-08-17 09:16:19.823 pm debugparse: mode=tilt

dev:20892021-08-17 09:16:19.820 pm traceparseSetDataResponse: descMap=[raw:catchall: 0104 EF00 01 01 0040 00 2C9C 01 00 0000 02 01 00006504000100, profileId:0104, clusterId:EF00, clusterInt:61184, sourceEndpoint:01, destinationEndpoint:01, options:0040, messageType:00, dni:2C9C, isClusterSpecific:true, isManufacturerSpecific:false, manufacturerId:0000, command:02, direction:01, data:[00, 00, 65, 04, 00, 01, 00]]

dev:20892021-08-17 09:16:19.794 pm tracecheckHeartbeat: waitMillis=3999998

dev:20892021-08-17 09:16:19.790 pm debugupdatePresence: present=true

dev:20892021-08-17 09:16:19.676 pm traceparse: ACK command=0

dev:20892021-08-17 09:16:19.644 pm tracecheckHeartbeat: waitMillis=3999998

dev:20892021-08-17 09:16:19.640 pm debugupdatePresence: present=true

dev:20892021-08-17 09:16:18.956 pm tracesendTuyaCommand: message=76716504000100

dev:20892021-08-17 09:16:18.954 pm tracesendTuyaCommand: dp=0x65, dpType=0x04, fnCmd=0x00, fnCmdLength=2

dev:20892021-08-17 09:16:18.942 pm tracecheckForResponse: waitMillis=59995

dev:20892021-08-17 09:16:18.940 pm tracecheckForResponse: waitingForResponseSinceMillis=1629252978937

dev:20892021-08-17 09:16:18.936 pm debugsetMode: modeText=null, modeValue=0

dev:20892021-08-17 09:16:17.919 pm debugconfigure

Sorry if I'm dumping a lot of data. I really don't know how to read the logs but I am very much learning from those of you who are kind enough to help. If you see an obvious problem here, please let me know.

(Regarding your first post of logs...)

Assuming device 2088 is your virtual device and device 2089 are your "real" shades, then there are 202 milliseconds between the virtual device opening and the open() command being send to the real device. That's nearly instant and would point to something other than the virtual device or rule as being the problem to me--likely the real device itself. I am not familiar with the Tuya driver to know what most of the rest of the logs for those devices mean, though I don't see anything that looks unusual (though the copy/paste is hard to read).

I'm not sure I see anything in the second set of logs regarding the virtual device, so it's hard to comment on the timing there.

OK, quick dumb question from me - how do I tell what is device 2088 and device 2089? I don't see these numbers in the device details page nor on the device listing.

There are two easy-ish ways:

  • click the log level (info, debug, etc.) in that log entry and you'll be taken right to the device page; or
  • click the device ID (eg., dev:2088) and the logs will be filtered to just that device and its name will be highlighted at the top of the page.

Many log entries will also contain the device name (e.g., "Switch XYZ is on") in some log entries, though that is entirely up to the driver and I don't think is conventional for debug logs, just info/event (descriptionText) logs.

1 Like

Don't know if it is the problem but your raise routine looks at Master bedroom blinds and your lower routine looks' at Master bedroom blinds 1. It looks like blinds 1 is the real device, going by your rules.

2 Likes

OMG %&*$%&$%&(!!!!

(you're right, that's exactly it. pardon me while I drown in embarrassment from my own stupidity)

1 Like

It happens, sometimes we get so frustrated the obvious stuff eludes us.

1 Like

Who is able to point me in the direction to change the transition time? My blind needs about 25 seconds from 0% to 100% and the standard device time is about 10 seconds which I could not change yet. Thankful in advance.

In the device driver under "Preferences" there is a transition time option. It only has a number of fixed time options but 30s should be close enough?

Download the Hubitat app