Better Laundry Monitor Port & Update

potts.mike · December 13, 2020, 2:09pm

It seems like I am not the only one that is stumped with this?

csteele · December 13, 2020, 4:24pm

I've tried to duplicate. I created a Virtual PowerMeter and setup BLM to monitor it.

Using the Set Power tile and the Reset Power, I tried to quickly simulate your graph. Obviously there's no need for me to manually peck in 300 data points. Crossing the set thresholds a few times should be enough to demonstrate.

Logs:

app:434 2020-12-13 08:15:11.427 am  info  You are using the current version of this Application
app:434 2020-12-13 08:15:07.122 am  info  You are using the current version of this Application
app:434 2020-12-13 08:13:28.869 am  debug We hit delay 1 times
app:434 2020-12-13 08:13:28.855 am  debug Power: 0W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:12:48.965 am  debug We hit the delay 1 times but cleared it
app:434 2020-12-13 08:12:48.956 am  debug Power: 100W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:12:45.060 am  debug We hit delay 1 times
app:434 2020-12-13 08:12:45.044 am  debug Power: 0W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:12:11.480 am  debug We hit the delay 1 times but cleared it
app:434 2020-12-13 08:12:11.465 am  debug Power: 300W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:12:09.396 am  debug We hit delay 1 times
app:434 2020-12-13 08:12:09.372 am  debug Power: 0W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:11:50.093 am  debug We hit the delay 1 times but cleared it
app:434 2020-12-13 08:11:50.084 am  debug Power: 300W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:11:43.279 am  debug We hit delay 1 times
app:434 2020-12-13 08:11:43.258 am  debug Power: 0W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:11:03.851 am  debug Power: 300W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:10:48.176 am  debug Power: 7W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:10:03.177 am  debug Power: 88W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:09:59.296 am  debug Power: 7W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:09:27.305 am  debug Cycle started.
app:434 2020-12-13 08:09:27.296 am  debug fixed: today at 8:09am
app:434 2020-12-13 08:09:27.256 am  debug Power: 85W, State: null, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:08:39.476 am  debug Power: 7W, State: null, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
--- Live Log Started, waiting for events ---

As you can see, the "stop" threshold was crossed several times, followed by values above the stop threshold. as shown by: "We hit the delay 1 times but cleared it"

The last log is:
We hit delay 1 times

And there it will sit til another Zero Power message arrives OR til the 90 min deadman fires.

I'm torn here.. in simulating your numbers.. do I fire another Zero Power message and thus show that it correctly ends, OR wait 90 mins...

I think I'll send the Zero and verify that, at least.. then alter the Thresholds to have a 9 min Deadman... and do the whole thing again.

I did, and the Logs show:

app:434 2020-12-13 08:31:09.817 am debug Cycle finished after delay.
app:434 2020-12-13 08:31:09.758 am debug send: Mike's laundry is done
app:434 2020-12-13 08:29:09.643 am debug Ending duration is set, waiting
app:434 2020-12-13 08:29:09.622 am debug Power: 0W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:29:08.302 am debug Ending duration is set, waiting
app:434 2020-12-13 08:29:08.263 am debug Power: 1W, State: true, thresholds: 25.0 4.0 2 2 optional: 700.0 null 90
app:434 2020-12-13 08:15:11.427 am info  You are using the current version of this Application
app:434 2020-12-13 08:15:07.122 am info  You are using the current version of this Application
app:434 2020-12-13 08:13:28.869 am debug We hit delay 1 times

I'm going to alter the Thresholds and try again...

2nd pass Logs:

app:434 2020-12-13 08:45:49.037 am debug We hit delay 1 times
app:434 2020-12-13 08:45:49.024 am debug Power: 1W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:45:22.148 am debug We hit the delay 1 times but cleared it
app:434 2020-12-13 08:45:22.129 am debug Power: 324W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:45:16.763 am debug We hit delay 1 times
app:434 2020-12-13 08:45:16.747 am debug Power: 0W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:45:00.903 am debug We hit the delay 1 times but cleared it
app:434 2020-12-13 08:45:00.894 am debug Power: 323W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:44:57.819 am debug We hit delay 1 times
app:434 2020-12-13 08:44:57.807 am debug Power: 0W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:44:53.514 am debug We hit the delay 1 times but cleared it
app:434 2020-12-13 08:44:53.505 am debug Power: 322W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:44:28.166 am debug We hit delay 1 times
app:434 2020-12-13 08:44:28.140 am debug Power: 0W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:44:17.556 am debug Power: 321W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:44:10.760 am debug Power: 7W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:43:57.035 am debug Power: 88W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:43:51.267 am debug Power: 7W, State: true, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:43:29.888 am debug Cycle started.
app:434 2020-12-13 08:43:29.853 am debug Power: 88W, State: false, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5
app:434 2020-12-13 08:43:05.832 am debug Power: 7W, State: false, thresholds: 25.0 4.0 2 0 optional: 700.0 null 5

And now I'm just waiting on the 5 min Deadman timer...

app:434 2020-12-13 08:48:29.999 am debug Cycle finished by deadman timer. State: false
app:434 2020-12-13 08:48:29.963 am debug send: Mike's laundry is done
app:434 2020-12-13 08:45:49.037 am debug We hit delay 1 times

So... the results follow my expectations. In addition to shortening the Deadman delay to 5 mins to speed the test results, I cleared the Stop Power for Continuous Minutes (4th Threshold value). The Stop after Sequential and the Stop Power for Continuous Minutes (3rd and 4th values) are rarely needed together, usually it's one or the other.

potts.mike · December 15, 2020, 2:41am

I made the changes that you suggested and got my notifications. Thanks for the help with this.

ross2 · February 27, 2021, 6:15pm

It seems like there is a bug in this app if the power switch sends reports less than 60 seconds apart.

You can see in the log below that it should delay 1 minute after power has been below 4w for two consecutive readings. However, the ending keeps getting pushed out by each update, until the final update that comes 60 seconds after the previous one.

	app:1662021-02-23 02:47:38.217 pm debugCycle finished after delay.
	app:1662021-02-23 02:47:38.207 pm debugfixed: today at 2:47pm
	app:1662021-02-23 02:47:38.155 pm debugsend: Washing machine is finished
	app:1662021-02-23 02:47:38.102 pm debugPower: 1.616W, State: false, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:47:08.135 pm debugPower: 1.610W, State: false, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:46:38.394 pm debugCycle finished after delay.
	app:1662021-02-23 02:46:38.382 pm debugfixed: today at 2:46pm
	app:1662021-02-23 02:46:38.223 pm debugsend: Washing machine is finished
	app:1662021-02-23 02:46:38.119 pm debugEnding duration is set, waiting
	app:1662021-02-23 02:46:38.109 pm debugPower: 1.549W, State: true, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:45:38.117 pm debugEnding duration is set, waiting
	app:1662021-02-23 02:45:38.103 pm debugPower: 1.663W, State: true, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:45:08.386 pm debugEnding duration is set, waiting
	app:1662021-02-23 02:45:08.378 pm debugPower: 1.628W, State: true, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:44:38.085 pm debugEnding duration is set, waiting
	app:1662021-02-23 02:44:38.076 pm debugPower: 1.590W, State: true, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:44:08.138 pm debugEnding duration is set, waiting
	app:1662021-02-23 02:44:08.128 pm debugPower: 1.663W, State: true, thresholds: 10.0 4.0 2 1 optional: 1500.0 null null
	app:1662021-02-23 02:43:38.126 pm debugEnding duration is set, waiting

I'm new to Hubitat Groovy, but it looks like the scheduling of cycleDone() on each run of powerHandler() keeps extending the time the check should occur. If it could check if its already been scheduled and hasn't yet run, it could skip rescheduling it.

This is with version 1.4.7

jlv · March 2, 2021, 5:03pm

When I try to install via HPM, I get this error:

Error Occurred During Installation
An error occurred while installing the package: Failed to install app https://raw.githubusercontent.com/HubitatCommunity/Hubitat-BetterLaundryMonitor/master/BetterLaundryMonitor_Child.groovy. Please notify the package developer..

I'm just going to install by hand.

csteele · March 2, 2021, 5:50pm

Just tried HPM and it installed it without error.

I then uninstalled it and Installed it again. No error for me.

I also did a Repair of a previously Installed package on a completely different Hub. No Error.

jlv · March 2, 2021, 6:20pm

Yes, this was weird. I've never gotten an error from HPM before for the dozen of other things I've installed. Before I install by hand, I'll try a reboot to see if that makes a difference. There was nothing useful in the logs, either:

Update: same behavior after a reboot. Debug logs from HPM don't add anything.

csteele · March 2, 2021, 6:31pm

My logs are even more useless.. nothing but successes

jlv · March 2, 2021, 6:34pm

Well, this is interesting. When I went to add the app by hand, I did so in the same order as HPM - the child app first (see logs above). Of course that fails as the parent app isn't installed:
Metadata Error: Parent App 'tierneykev:Better Laundry Monitor' not found on line 25

So there's an ordering issue in HPM.

csteele · March 2, 2021, 6:43pm

I'll have to circle back to HPM's documentation, but I thought that:

  "version": "1.4.4",
  "primary": true

for the Parent and:

  "version": "1.4.7",
  "primary": false

for the Child would set the order.

jlv · March 2, 2021, 6:45pm

I was just reading the HPM doc. I don't see anything that gives ordering for multiple apps in the package. I thought the version was separate per file.

One thing I did notice is that you have the parent app marked as optional ("required": false). I suspect it might be installing all the required items first, then the optional ones. I'm not sure why you have it optional, since it obviously can't install the child without the parent.

csteele · March 2, 2021, 6:47pm

I read it the other way... there's no point in installing the Parent without the Child, so the child is the required one.

UPDATE:
I modified the manifest to be "required": true for both.

jlv · March 2, 2021, 7:01pm

That fixed it. Installation via HPM just succeeded.

MMMmmmm · March 6, 2021, 3:18pm

So what is the latest version of BLM to use?

HAL9000 · March 6, 2021, 3:25pm

According to Hubitat Package Manager:

Hubitat-BetterLaundryMonitor

Better Laundry Monitor v1.4.4 (app)
Better Laundry Monitor - Power Switch v1.4.7 (app)

sdjme · March 12, 2021, 6:40am

Hi there,

So BLM has been chugging along for months perfectly. Tonight I noticed that it seemed to have been missing cycle ends, and even appeared to ignore the deadman time.

So I started tweaking. I kept my power thresholds the same (on above 150, off below 40) but lowered the stop after 2 reports and stop after 2 minutes. So my question is... why did this take a little extra to report?

app:562021-03-11 10:28:30.178 pm debugCycle finished after delay.
app:562021-03-11 10:28:30.165 pm debugfixed: today at 10:28pm
app:562021-03-11 10:28:29.471 pm debugsend: Warm clothes are waiting in the dryer!
app:562021-03-11 10:26:29.389 pm debugEnding duration is set, waiting
app:562021-03-11 10:26:29.375 pm debugPower: 0.000W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:26:29.331 pm infoLG Dryer power is 0.000 W
app:562021-03-11 10:26:00.476 pm debugEnding duration is set, waiting
app:562021-03-11 10:26:00.460 pm debugPower: 6.729W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:26:00.288 pm infoLG Dryer power is 6.729 W
app:562021-03-11 10:25:30.569 pm debugEnding duration is set, waiting
app:562021-03-11 10:25:30.555 pm debugPower: 6.673W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:25:30.505 pm infoLG Dryer power is 6.673 W
app:562021-03-11 10:24:59.333 pm debugEnding duration is set, waiting
app:562021-03-11 10:24:59.318 pm debugPower: 6.668W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:24:59.266 pm infoLG Dryer power is 6.668 W
app:562021-03-11 10:24:30.671 pm debugEnding duration is set, waiting
app:562021-03-11 10:24:30.655 pm debugPower: 9.604W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:24:30.610 pm infoLG Dryer power is 9.604 W
app:562021-03-11 10:24:28.631 pm debugWe hit delay 1 times
app:562021-03-11 10:24:28.619 pm debugPower: 19.363W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:24:28.569 pm infoLG Dryer power is 19.363 W
app:562021-03-11 10:24:00.366 pm debugPower: 1022.283W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:1232021-03-11 10:23:25.638 pm infoLG Washer energyDuration is 1.27 Hours 
app:562021-03-11 10:23:00.366 pm debugPower: 1027.730W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:23:00.323 pm infoLG Dryer power is 1027.730 W
app:562021-03-11 10:22:30.382 pm debugPower: 1039.474W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:22:30.331 pm infoLG Dryer power is 1039.474 W
app:562021-03-11 10:22:00.369 pm debugPower: 1031.910W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90
dev:372021-03-11 10:22:00.318 pm infoLG Dryer power is 1031.910 W
app:562021-03-11 10:21:30.708 pm debugPower: 1026.746W, State: true, thresholds: 150.0 40.0 2 2 optional: 1500.0 null 90

If I'm reading the logs correctly--and understand the configuration--it seems to have started the 2 minute timer when the power report finally reached zero (at 10:26:29), and not the low threshold (10:24:28). Is that right?

ross2 · March 22, 2021, 10:35pm

I've fixed this issue and have a pull request open at Fix bug with power updates more frequent than delayEndDelay by kcstrom · Pull Request #12 · HubitatCommunity/Hubitat-BetterLaundryMonitor · GitHub

sburke781 · August 7, 2021, 3:29am

Any chance of removing / making the debug message for corrections to the date/time optional in the Power Switch driver at the end of the fixDateTimeString method? I'm thinking a preference setting somewhere that could be used to turn debug messages on/off.

csteele · August 7, 2021, 4:13am

v1.4.9 released.

sburke781 · August 7, 2021, 4:18am

Wow, thanks for such a quick turnaround.