Capture/restore attributes is and has always been flaky for me. Why?

#1

I’ve been using Webcore for 4 or 5 years. Two of the most useful commands are the capture and restore attributes commands. Unfortunately, they work maybe 50-70% of the time for.me I’ve added wait statements after the capture and before the restore. I’ve also tried saving to named local and global stores. Sometimes the commands work, sometimes they don’t. Which can really mess things up. This is both on the ST and HE platforms.

I’ve started creating variables and capturing device states to these variables but if I’m working with more than a couple of devices, it’s really time consuming.

So here’s my question: Is it just me? Does anyone else use these commands and have consist results? I’m trying to figure out if my mesh is weak or if the commands are just unreliable. Or if it’s something else entirely. TIA for any info.

#2

Can you show what you are doing, logs (for HE).

You can for the piston doing this enable command execution delay if you wish to space commands out. You also if using older devices may need to disable command optimization if you have older devices that do not update frequently.

I changed the save/restore on HE, so it is different than ST because of issues I found.

#3

I don’t have older logs as I usually only turn on logging when I’m troubleshooting but I did make the changes you suggested and tested one of my pistons a couple of times a few minutes ago. So far, so good.

I did shut down my hub for 20 minutes this morning in an attempt to rebuild the Zigbee mesh so a janky mesh may have been part of the problem. I’ve attached the piston and the log from this morning’s successful tests. Let me know if you see any other opportunities to optimize things.

I’ll make the same changes to my other pistons and report back in a few days. I was unaware of the command execution delay option so thanks for that info.

Capture%20Atts
Capture Atts.png1178×721 67.7 KB

10/4/2022, 9:22:13 AM +496ms
+4ms ╔Received event [Home].time = 1664896933440 with a delay of 56ms, canQueue: true, calledMyself: false
+18ms ║RunTime initialize > 17 LockT > 0ms > r9T > 2ms > pistonT > 0ms (first state access 15 5 12)
+21ms ║Runtime (9051 bytes) initialized in 2ms (v0.3.114.20220714_HE)
+31ms ║╔Execution stage started
+49ms ║║Executed physical command [Right Most Patio Light].off() (14ms)
+83ms ║║Executed physical command [Right Patio Light].setLevel(1) (19ms)
+89ms ║╚Execution stage complete. (58ms)
+94ms ╚Event processed successfully (90ms)
10/4/2022, 9:22:12 AM +31ms
+6ms ╔Received event [Home].time = 1664896931973 with a delay of 58ms, canQueue: true, calledMyself: false
+20ms ║RunTime initialize > 18 LockT > 1ms > r9T > 2ms > pistonT > 0ms (first state access 15 7 11)
+23ms ║Runtime (9034 bytes) initialized in 2ms (v0.3.114.20220714_HE)
+36ms ║╔Execution stage started
+76ms ║║Executed physical command [Left Most Patio Light].setLevel(1) (21ms)
+78ms ║║Executed virtual command [Left Most Patio Light].loadStateLocally (28ms)
+87ms ║║Injecting command execution delay of 45ms before [Left Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:22:12 AM MDT (in 44ms) for 6 (st:-3 / [d::04ae6279424a9d56dff7f01c31f2d147:, c:setLevel, p:[1], task:12, dc:false, ig:true])
+89ms ║║Executed virtual command [Left Patio Light].loadStateLocally (7ms)
+98ms ║║Injecting command execution delay of 109ms before [Patio Lights].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:22:12 AM MDT (in 108ms) for 6 (st:-3 / [d::4c5a6d7f573ba37055f72c7550cc7b26:, c:setLevel, p:[25], task:12, dc:false, ig:true])
+99ms ║║Executed virtual command [Patio Lights].loadStateLocally (7ms)
+108ms ║║Injecting command execution delay of 174ms before [Right Most Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:22:12 AM MDT (in 173ms) for 6 (st:-3 / [d::bbb48272acf93304ec37c3c5dd9b32bb:, c:setLevel, p:[5], task:12, dc:false, ig:true])
+111ms ║║No command execution delay required wait before command delay: 1300 Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:22:13 AM MDT (in 1299ms) for 6 (st:-3 / [d::bbb48272acf93304ec37c3c5dd9b32bb:, c:off, p:null, task:12])
+112ms ║║Executed virtual command [Right Most Patio Light].loadStateLocally (10ms)
+122ms ║║Injecting command execution delay of 1365ms before [Right Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:22:13 AM MDT (in 1364ms) for 6 (st:-3 / [d::1cf5369da39ddebadc8c8d39937d161e:, c:setLevel, p:[1], task:12, dc:false, ig:true])
+124ms ║║Executed virtual command [Right Patio Light].loadStateLocally (8ms)
+125ms ║║executeTask: Waiting for 100ms; lastPause: null
+234ms ║║Executed virtual command [Left Most Patio Light, Left Patio Light, Patio Lights, Right Most Patio Light, Right Patio Light].setVariable (3ms)
+266ms ║║Executed physical command [Left Patio Light].setLevel(1) (16ms)
+296ms ║║Executed physical command [Patio Lights].setLevel(25) (15ms)
+329ms ║║Executed physical command [Right Most Patio Light].setLevel(5) (18ms)
+338ms ║╚Execution stage complete. (302ms)
+387ms ║Setting up scheduled job for Tue, Oct 4 2022 @ 9:22:13 AM MDT (in 1097ms),with 1 more job pending
+390ms ╚Event processed successfully (385ms)
10/4/2022, 9:21:11 AM +589ms
+5ms ╔Received event [Home].execute = [192.168.1.98] with a delay of 34ms, canQueue: true, calledMyself: false
+19ms ║RunTime initialize > 17 LockT > 1ms > r9T > 3ms > pistonT > 0ms (first state access 13 7 10)
+23ms ║Runtime (8915 bytes) initialized in 3ms (v0.3.114.20220714_HE)
+26ms ║╔Execution stage started
+36ms ║║Comparison (boolean) false is (boolean) false = true (3ms)
+38ms ║║Condition #2 evaluated true (7ms)
+45ms ║║Comparison (enum) on is (string) on = true (1ms)
+47ms ║║Condition #3 evaluated true (8ms)
+49ms ║║Condition group #1 evaluated true (condition did not change) (18ms)
+57ms ║║Executed virtual command setVariable (2ms)
+72ms ║║Executed virtual command [Left Most Patio Light].saveStateLocally (3ms)
+77ms ║║Executed virtual command [Left Patio Light].saveStateLocally (2ms)
+83ms ║║Executed virtual command [Patio Lights].saveStateLocally (3ms)
+89ms ║║Executed virtual command [Right Most Patio Light].saveStateLocally (2ms)
+96ms ║║Executed virtual command [Right Patio Light].saveStateLocally (3ms)
+172ms ║║Executed virtual command [Left Most Patio Light, Left Patio Light, Patio Lights, Right Most Patio Light, Right Patio Light].wait (1ms)
+179ms ║║executeTask: Waiting for 100ms; lastPause: null
+304ms ║║Executed physical command [Left Most Patio Light].on() (18ms)
+305ms ║║Executed [Left Most Patio Light].on (20ms)
+311ms ║║Injecting command execution delay of 54ms before [Left Patio Light].on() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:11 AM MDT (in 53ms) for 6 (st:-3 / [d::04ae6279424a9d56dff7f01c31f2d147:, c:on, p:[], task:9, dc:false, ig:true])
+312ms ║║Executed [Left Patio Light].on (4ms)
+318ms ║║Injecting command execution delay of 122ms before [Patio Lights].on() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 121ms) for 6 (st:-3 / [d::4c5a6d7f573ba37055f72c7550cc7b26:, c:on, p:[], task:9, dc:false, ig:true])
+319ms ║║Executed [Patio Lights].on (4ms)
+324ms ║║Injecting command execution delay of 191ms before [Right Most Patio Light].on() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 190ms) for 6 (st:-3 / [d::bbb48272acf93304ec37c3c5dd9b32bb:, c:on, p:[], task:9, dc:false, ig:true])
+326ms ║║Executed [Right Most Patio Light].on (4ms)
+332ms ║║Injecting command execution delay of 259ms before [Right Patio Light].on() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 258ms) for 6 (st:-3 / [d::1cf5369da39ddebadc8c8d39937d161e:, c:on, p:[], task:9, dc:false, ig:true])
+333ms ║║Executed [Right Patio Light].on (3ms)
+342ms ║║Injecting command execution delay of 324ms before [Left Most Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 323ms) for 6 (st:-3 / [d::3864f2f57190fe9202e2945ba89871e6:, c:setLevel, p:[95], task:10, dc:false, ig:true])
+344ms ║║Executed [Left Most Patio Light].setLevel W (6ms)
+351ms ║║Injecting command execution delay of 392ms before [Left Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 391ms) for 6 (st:-3 / [d::04ae6279424a9d56dff7f01c31f2d147:, c:setLevel, p:[95], task:10, dc:false, ig:true])
+352ms ║║Executed [Left Patio Light].setLevel W (5ms)
+359ms ║║Injecting command execution delay of 459ms before [Patio Lights].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 458ms) for 6 (st:-3 / [d::4c5a6d7f573ba37055f72c7550cc7b26:, c:setLevel, p:[95], task:10, dc:false, ig:true])
+360ms ║║Executed [Patio Lights].setLevel W (5ms)
+367ms ║║Injecting command execution delay of 526ms before [Right Most Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 525ms) for 6 (st:-3 / [d::bbb48272acf93304ec37c3c5dd9b32bb:, c:setLevel, p:[95], task:10, dc:false, ig:true])
+368ms ║║Executed [Right Most Patio Light].setLevel W (5ms)
+376ms ║║Injecting command execution delay of 593ms before [Right Patio Light].setLevel() added schedule Requesting a physical command wake up at Tue, Oct 4 2022 @ 9:21:12 AM MDT (in 592ms) for 6 (st:-3 / [d::1cf5369da39ddebadc8c8d39937d161e:, c:setLevel, p:[95], task:10, dc:false, ig:true])
+377ms ║║Executed [Right Patio Light].setLevel W (5ms)
+384ms ║║Executed virtual command [Left Most Patio Light, Left Patio Light, Patio Lights, Right Most Patio Light, Right Patio Light].wait (0ms)
+387ms ║║Requesting wake up at Tue, Oct 4 2022 @ 9:22:11 AM MDT (in 59998ms) for 6 (st:11)
+416ms ║║Executed physical command [Left Patio Light].on() (14ms)
+428ms ║║Synchronizing scheduled event, waiting for 11ms; lastPause: 1664896871870
+459ms ║║Executed physical command [Patio Lights].on() (15ms)
+471ms ║║Synchronizing scheduled event, waiting for 44ms; lastPause: 1664896872029
+538ms ║║Executed physical command [Right Most Patio Light].on() (18ms)
+549ms ║║Synchronizing scheduled event, waiting for 40ms; lastPause: 1664896872104
+614ms ║║Executed physical command [Right Patio Light].on() (20ms)
+626ms ║║Synchronizing scheduled event, waiting for 39ms; lastPause: 1664896872179
+687ms ║║Executed physical command [Left Most Patio Light].setLevel(95) (17ms)
+700ms ║║Synchronizing scheduled event, waiting for 41ms; lastPause: 1664896872255
+764ms ║║Executed physical command [Left Patio Light].setLevel(95) (17ms)