It’d be helpful to see the events.log for a working caldav-command update of your “min” Item
That’s correct. That comes from autoupdate, and
(a) it only appears if a command is expected to make a change e.g. send command ON to a switch with current state OFF, and
(b) autoupdate can be optionally disabled per Item.
This messaging from autoupdate is new in 2.4
This stuff is important here, because if the caldav binding is sending commands and you are looking at states, you are totally reliant on autoupdate working.
I don’t like the long names, but I’m sure other people would have run into this before if there was an issue? Won’t rule it out though - some localised truncation effect would make both your long names appear to refer to the same Item sometimes.
I don’t like these numeric-only commands being sent to Number:Temperature type Items, because they expect something like 27°C
I’ve little idea of what you are “supposed” to send instead, this UoM stuff seems to be a bit trial and error for me.
No idea why your Items behave differently if its a UoM issue. You seem to be saying there’s persistence involved here as well, restore on startup perhaps?
The file I uploaded is every events.log entry associated with these Items since I implemented the CalDav binding a few weeks ago.
Yes, the names are long… but this can’t be the reason as Min is the same length.
UOM - yup. I am confused by this as well. But I defined them as Temperatures because my Nest Items are defined accordingly per the Nest binding documentation. I am using these “CalDav” setpoints with my Nest Items. But, again, Min works.
Persistence - correct. I’m using mapdb to restore values on startup. That’s the only way I can explain that the value “returned” to the Item after I had deleted it from the registry (during the name change experiment).
I did stop openHAB and start it again after I had changed the name of the Item. I did not reboot. I did not clear the cache & temp files. I was just trying to ensure that the old Item declaration wasn’t “lost in space” during the name change.
I guess that’s a filtered log. It contains not a single instance of any openHAB Item state change… Based on that, neither of your Items is working - but I expect its just a filtering thing?
All I wanted was to see the expected events - command to min Item autoupdate prediction for min Item min Item state change
and compare with a failing max example.
We could go at this the brute force way:
Create two plain Number type Items with short names.
Add those to caldav-command. (Can you add, or must it be replace?)
Don’t mess with persistence yet.
Shut down OH.
Find and destroy cached caldavio.config, caldavCommand.config, they will get recreated from caldav.cfg etc.
Reboot.
Test.
When working, restore your long names, temperature type, persistence, etc. until trouble shows up.
I didn’t explicitly implement any log filtering myself. Is there somewhere I can look to clear any filters? This “filtering” is system wide as I don’t have any messages of that sort in my log for any Items, regardless of binding.
I think that capturing the information you mention would be a good next step before the steps you outline. Then I’ll start on the “reconfiguration” of this set of Items.
In the interim, regarding CalDav… I had many issues getting CalDav to function properly. I finally found several topics that explained that one had to create caldavio.cfg to prepend caldavio: to each option in the file. I also created caldavCommand.cfg manually… although it is a very simple configuration.
Any direction on logging and getting the additional information to be logged? Attached is my org.ops4j.pax.logging.cfg (I changed the extension so that I could upload it).
That’s weird then. Beyond my knowledge I’m afraid, hopefully someone else can help. Just to confirm, it is events.log we’re looking at.
As for configuration, yes 1.x bindings require xxx.cfg files.
Also as I understand it, part of the OH2 support of 1.x caches your xxx.cfg in a new file xxx.config, which appears to sometimes catch folk out when changes are made. So as a precaution, if you change xxx.cfg, stop OH and delete xxx.config to enforce changes.
There’s no way this 1.x binding understands UoM, so it’s a case of if a UoM Item supports non-dimensioned number updates and if autoupdate handles the case. I’m not convinced about that
I don’t think we can be so sure. If the name gets truncated somehow, then it’s possible that only the first long Item matches. What if you made the different part between the two be at the front instead of the end of the file name.
Correct and typically we cannot use UoM willy nilly. It needs to be supported by the binding I think.
Yes, events.log. Let’s see if anyone can weigh in on how I can get more detailed logging.
As you can tell, I’m not relishing rolling name changes throughout all the Calendar entries. What we’re not discussing regarding reconfiguring or changing the naming convention is headed in that direction.
CalDav is an “oddball” binding it appears. I think it’s just reading the calendar events and, in essence, generating DSL (I say this in a conceptual terms). What I mean is, caldavCommand reads the Calendar events. It interprets the BEGIN (or END) and sets a cron trigger for the time of each Calendar event. It then looks at the rest of the entry, which in my case is the syntax for setting an Item value. It generates item.sendCommand(value). Thus, the code triggers at the set cron time and runs the setCommand(s). So, the CalDav binding cares less about the data type of each Item. If I have not properly associated the Item and the value, it is the binding associated with the Item that will handle the error, not CalDav. So, the question of sendCommand setting a “plain” value (without any UOM) to an Item that is defined as a Temperature is an issue which should be handled there (i.e., not by CalDav).
Have you modified your logging config? The missing lines we are talking about should just appear there as of OH 2.4.
So far it’s the only thing that we can point to as being the problem. You changed the name and it worked. You changed it back and it stopped working again. There is something wrong and changing the name fixed it.
Which leads back to rossko’s statement above. We don’t know that it is handled there. It might require you to append the units in order for it to work.
Can someone point me to where I can grab the original logging config file that came with 2.4 (release)?
BTW, I uploaded my customized logging config in this post (Item State not Updating) a couple of posts ago.
The interesting thing is that the Max Item was receiving updates when I first set up CalDav. That’s how that 75 got in there in the first place. I’m not sure what changed (it actually might have been when I installed 2.4 release!).
When I was installing SNAPSHOTs I was being careful to save my modified version and then incorporating my changes to the file that came with the SNAPSHOT. To be honest, I hadn’t installed a new OH version in several weeks and I may not have been careful to go through this process when I grabbed the release version.
My updates only include adding some custom loggers for some of my own logging (power monitoring, temperature) and redirecting Chromecast & Samsung to their own files when I was helping test those bindings.
I’ll start with the “as released” configuration file and once I’m getting all the detailed logging we’re expecting, I’ll go back and add my mods.
Out of curiosity, I used REST API to command plain numbers to an existing Number:Temperature UoM Item. (OH 2.4 release)
Seems to work, accepting the value as being in the “current” dimension, °C in my case.
events.log
2019-02-27 22:33:22.504 [ome.event.ItemCommandEvent] - Item 'nmt_CurrentTemperature' received command 12
2019-02-27 22:33:22.509 [nt.ItemStatePredictedEvent] - nmt_CurrentTemperature predicted to become 12
2019-02-27 22:33:22.530 [vent.ItemStateChangedEvent] - nmt_CurrentTemperature changed from 21.5 °C to 12.0 °C
What’s the current dimension then, if its not specified in the command/update? The UoM framework seems to guess this based on clues from the Items label format [ ]
Mine, like yours, is specified [%.0f %unit%] - no actual clue there.
but -
The Item was previously updated by a 2.x (weather) binding that does understand UoM and populated the Item with e.g. 10 °C, so Item has picked up this, uhm, flavour of °C
also -
°C is the default for Number:Temperature anyway.
I also created a brand new Number:Temperature Item from xxx.items file
with “label [%.0f %unit%]”, so no clues inbuilt.
Used REST API to send plain number, accepted and updated from NULL to 12.0 °C, demonstrating the default in action.
(I would guess your locale defaults °F)
All of which says you can command plain numbers at Number:Temperature Items and expect autoupdate to do something.
I am more convinced about that now
What is not clear from all this is how persistence/restore-on-startup interacts. I would guess it stores/restores plain numbers and lets the UoM sort it out.
I think the long names issue is a red herring too, since we have correct looking logs of commands issued by caldav
I created two new Items identical to yours, used REST API to command
events.log
2019-02-28 00:19:58.697 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 12
2019-02-28 00:19:58.709 [vent.ItemStateChangedEvent] - SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin changed from NULL to 12.0 °C
2019-02-28 00:21:20.416 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 22
2019-02-28 00:21:20.429 [vent.ItemStateChangedEvent] - SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax changed from NULL to 22.0 °C
2019-02-28 00:21:47.113 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 33
2019-02-28 00:21:47.123 [vent.ItemStateChangedEvent] - SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax changed from 22.0 °C to 33.0 °C
2019-02-28 00:22:26.724 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 44
2019-02-28 00:22:26.739 [vent.ItemStateChangedEvent] - SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin changed from 12.0 °C to 44.0 °C
I’m pretty sure caldav will use the same REST methods to communicate with openHAB, since there’s no real binding to Items?
I have increased some of the logging levels from WARN to INFO. I’ll track whether I start seeing additional messages being logged. The Chromecast binding generates so many “update” errors… hopefully this additional logging will generate the information for this issue… and I’ll turn those back off. I’ll report more tomorrow.
2019-02-27 21:00:00.052 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 72
2019-02-27 21:00:00.058 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 75
2019-02-27 23:30:00.023 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 67
2019-02-27 23:30:00.043 [vent.ItemStateChangedEvent] - SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin changed from 72.0 °F to 67.0 °F
2019-02-27 23:30:00.052 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 75
2019-02-28 00:00:00.073 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 67
2019-02-28 00:00:00.085 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 75
2019-02-28 02:39:59.280 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 67
2019-02-28 02:39:59.285 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 75
2019-02-28 03:00:00.059 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 67
2019-02-28 03:00:00.079 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 76
2019-02-28 06:45:00.013 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin' received command 72
2019-02-28 06:45:00.026 [ome.event.ItemCommandEvent] - Item 'SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMax' received command 76
2019-02-28 06:45:00.036 [vent.ItemStateChangedEvent] - SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureMin changed from 67.0 °F to 72.0 °F
2019-02-28 03:00:00.079
This event should have generated a changed from log message since the value was 75 (and it is… “stuck” at 75) and the change should have been to 76… but it didn’t do anything.
The two items I have set up in CalDav doesn’t generate that much log “traffic”. It was easy to capture all activity related to these two Items using grep.
OK, I bit the bullet and changed all instances of SPT_house_VT_hallway_wall_sensor_thermostat_TargetTemperatureM to sptHouse_VT_thermostat_TargetTemperatureM and both newly named Items appear to be updating as expected (at least at this point in time). I’ll watch the next couple schedule transitions to make sure both values are updating.
2019-02-28 14:00:18.440 [ome.event.ItemCommandEvent] - Item 'sptHouse_VT_thermostat_TargetTemperatureMin' received command 72
2019-02-28 14:00:18.444 [ome.event.ItemCommandEvent] - Item 'sptHouse_VT_thermostat_TargetTemperatureMax' received command 75
2019-02-28 14:00:18.454 [vent.ItemStateChangedEvent] - sptHouse_VT_thermostat_TargetTemperatureMin changed from NULL to 72.0 °F
2019-02-28 14:00:18.460 [vent.ItemStateChangedEvent] - sptHouse_VT_thermostat_TargetTemperatureMax changed from NULL to 75.0 °F
Perhaps it was an Item name length issue. I’m more inclined to think that it was simply creating a new Item that set this on its way. However, if this issue is related to the length of the Item name, then there is some underlying bug or undocumented name length limit in OH that ought to be logged as a potential issue to investigate.
I would say that this topic can be CLOSED… but it is not SOLVED.
I think you just had a “damaged” Item in some way - a possible fix would be to delete it from the internal JSON store and allow it to be recreated from file on reboot.
