Network UPS Tools binding for openHAB 2 available

Tags: #<Tag:0x00007f745983e440>

As part of my quest to write a tutorial on how to migrate an openHAB1 binding to an openHAB 2 binding I’ve picked up the openHAB1 networkupstools binding to migrate. The actual code is very small and easy to migrate. However the biggest challenge is to define things and channels. With the openHAB 1 binding this is all free format. So you as a user must specify the items that link directly to the information of the network ups tool. With openHAB 2 the intention is to define a set of channels. This would make it possible to configure the channels from a user interface.

To do so I’d like to have some input from actual users. I have the following questions:

  1. UPS can be daisychained, linking multiple UPS. Is this something that should be supported by the binding?
  2. UPS can report information about several outlet’s. Should outlets be supported?
  3. The list of information provided by the UPS is very long. Can we make a selection of channels to support? Here is the complete list of possible channels: https://github.com/networkupstools/nut/blob/master/docs/nut-names.txt
  4. It seems also possible to send commands. I don’t know if that works. But is this of interest? And if so, which commands?

Alpha version available Binding merged and will be available in M4 2.5

The binding is available from Milestone 4 2.5. For older installations a jar file can be downloaded from: https://github.com/Hilbrand/openhab2-addons/releases/tag/networkupstools Place the jar file in your addons folder.

If you want any nut variable as channel available in the binding or have any other feedback let me know in the comments.

openHAB 1 migration guide:

If you used the openHAB 1 version of this binding. Here is the information to help you migrate to the new version.

The networkupstools.cfg needs to be migrated to a thing in a .things file or added via PaperUI:

oh1 binding config:

ups1.device=ups
ups1.host=192.168.1.10
ups1.login=admin
ups1.pass=pass
refresh=60000

oh2 thing configuration:
(Out-of-the-box channels don’t need to be configured. But it’s also possible to add additional channels. The configuration below makes use of this feature. See the readme for more information)

Thing networkupstools:ups:ups1 [ device="ups", host="192.168.1.10", username="admin", password="pass", refresh=60 ] {
    Channels:
        Number:ElectricPotential : upsOutputVoltage "UPS Output Voltage" [networkupstools="output.voltage", unit="V"]
}

Note:

  • refresh time changed from milliseconds to seconds: 60000 => 60
  • login changed to username as that better reflects how it’s called in network ups tools
  • pass changed to password

Items

oh1 items:

Number Ups_Realpower "UPS Power [%d W]" (Ups) {networkupstools="ups1:ups.realpower"}
Number Ups_Output_Voltage "UPS output voltage [%.1f V]" (Ups) {networkupstools="ups1:output.voltage"}
String Ups_Status "UPS status [%s]" (Ups) {networkupstools="ups1:ups.status"}

oh2 items:

Number:Power Ups_Realpower "UPS Power [%d W]" (Ups) {channel="networkupstools:ups:ups1:upsRealpower"}
Number:ElectricPotential Ups_Output_Voltage "UPS output voltage [%.1f V]" (Ups) {channel="networkupstools:ups:ups1:upsOutputVoltage"}
String Ups_Status "UPS status [%s]" (Ups) {channel="networkupstools:ups:ups1:status"}
String Ups_Status_Text "UPS status [%s]" (Ups) {channel="networkupstools:ups:ups1:statusText"}

README on the official documentation page:

3 Likes

I have a UPS and I made a pretty lame attempt at setting up the OH1 version of the binding and did not get it to work. It was the first time I had ever tried to set up a OH1 binding. I know for one Rich uses the binding and I have bookmarked a couple of threads about setting it up but haven’t gotten around to doing so.
Anyhow…
I’m glad you are writing a tutorial for migrating bindings, Thank you Hilbrand
I’m glad the nut binding is getting updated
finally… the list of possible channels is daunting… that would be a lot of channels!
I don’t know how such a thing could be configured in the user interface without being really complex. and I’m glad someone is trying to figure out how to do this but I am not going to be much help. As I looked thru the list, there were things I’d like to be able to monitor, but how to pick which ones are important and not, oh boy!
I will watch this thread and git and assist in any way I can, testing documentation whatever

Well, I’m using Network Ups Tools successfully, the openHAB side is really easy to get to work (other than the NUT side, especially in windows :wink:

I’m only using a small set of Items, Voltage (In, Out for AC and DC), type and charge, would be nice to set shutdown time, although this would be configured at the NUT server itself, don’t know if there are other useful commands.

Nice work Udo, I would say yes sending commands and reporting outlets would be useful. Chaining? Less so.

There is ALOT of channels, perhaps there can be some kind of basic mode, with limited info/channels, and an advanced mode with all the channels?

Hi Hilbrand,
many thanks for picking the nut-binding as migration example. It’s one the my last openHAB-1 bindings, so happy to see it’s been migrated…

I’ve been using nut1-binding for a long time. I’m going to try answering your questions from my point of view biased by my current use case of course :wink:

Seems to me, that daisychaining is a less common setup. APC even recommends against it (https://www.apc.com/us/en/faqs/FA157424/)
Anyway … probably we should widen the question to:

Should the binding be prepared to deal with multiple UPS’s (regardless of the specific UPS configuration like daisy/parallel/etc.)?

I’d answer: Definitely yes.
Dealing with multiple things of the same type is likely intended already. So this should fulfill most needs as long as every single UPS can be hooked up to nut/openHAB by an individual connection.

Unfortunately, my UPS does not support this. If it had this option, I’d definitely be keen on getting measurements of the outlets or even being able to control them.

The list contains a superset of available readings over all the different brands/models of nut-supported UPS’s. The specific UPS driver usually supports just a subset of it.

Beside knowing if the UPS is on line-power or on battery, all the measurements (load/power/voltage/temperature/…) seem relevant to deserve feeding channels.

Unfortunately, the list of available readings depends on the UPS-brand/model and the nut-driver supporting it. Therefore it’s good to have multiple options available (even all?)

Example:
My UPS is supported by the usbhid-ups driver. This combination does not provide ups.load nor ups.power. But it provides battery.runtime. Using it, I can estimate, which load is currently applied to the UPS.

That said, I’d prefer making all the possible readings available to the binding and check, which variable is really there and provide this as channel.

I’ve tried to categorize the variables to set some priority from my point of view:

**MUST HAVE** (must be available as channel if the nut-driver provides it)
ups.status
ups.alarm
battery.charge
battery.runtime

**RELEVANT** (should be provided)
battery.voltage
input.transfer.reason
input.voltage
input.voltage.status
input.quality
input.current
input.current.status
input.load
input.realpower
ups.load
ups.power
ups.realpower
ups.temperature
ups.test.result

**NICE TO HAVE** (more or less informational or non-changing inventory information)
input.voltage.maximum
input.voltage.minimum
input.voltage.nominal
battery.charge.low
battery.charge.restart
battery.date
battery.runtime.low
battery.voltage.nominal
input.frequency
input.sensitivity
input.transfer.high
input.transfer.low
output.voltage.nominal
output.frequency
output.voltage
ups.date, ups.time
ups.delay.shutdown
ups.delay.start
ups.firmware, ups.firmware.aux
ups.id
ups.mfr.date
ups.realpower.nominal
ups.serial
ups.test.interval

Again: Just a first try to prioritize. Others may have different priorities - depends on the use case :wink:

My current setup just uses this:

Number UpsBattVoltage   "Batteriespannung [%.1f V]"     (gUsv, gPersistInflux)  {networkupstools="ups1:battery.voltage"}
Number UpsBattCharge    "Ladezustand [%.1f %]"          (gUsv, gPersistInflux)  {networkupstools="ups1:battery.charge"}
Number UpsBattRuntime   "Autonomiezeit [%.1f s]"        (gUsv, gPersistInflux)  {networkupstools="ups1:battery.runtime"}
String UpsState         "USV-Status [%s]"               (gUsv, gPersistInflux)  {networkupstools="ups1:ups.status"}

I do not use it at the moment(I guess my combination of usbhid-ups and my UPS does not support any).

EDIT: Just found out, the follwing commands are supported here:

  • beeper.disable
  • beeper.enable
  • beeper.mute
  • beeper.off
  • beeper.on
  • load.off
  • load.off.delay
  • shutdown.reboot
  • shutdown.stop

Not sure, if I really need them on the openHAB layer. Maybe using the beeper for additional notifications… Mmmh…

3 Likes

I’ve updated the original post with the information about the first alpha release of the binding. Since I don’t have a UPS (anymore) I haven’t tested the code (other than with unit tests and demo code). Also I had to rewrite the actual communication because I the original library could not be used. That might make it more prone for not working.

As mentioned in the post above. The features are very much open for change. So if you have any suggestions please let it be known. All feedback on how and if it works is appreciated!

1 Like
  1. I think that would be really awesome but I don’t have a good feel for how many home users would have more than one UPS like that. Maybe shoot for an initial MVP that doesn’t include it and add it later?

  2. I’m sure that someone somewhere would want to have this information. If it’s available it seems reasonable. I personally wasn’t even aware this information is available. Perhaps it’s not for my specific make and model of UPS.

  3. Not all of those channels will be available on all UPS. Mine only reports 38 from that list and I only use three of them in OH:

    • battery.charge
    • ups.load
    • battery.runtime
  4. This is something I was unaware of. I can’t say, I’d have to research what commands are available. I can’t foresee ever wanting to use them though.

That’s a list of all potential channels. @hilbrand, would it be possible to just discover which are available? Assuming the data comes across in the same format when you run upsc from the command line I’d imagine it would be pretty easy to determine which channels to make available. Though you would have to account for the full list somewhere I suspect.

I’ll definitely be trying it out and will report my experiences. Thanks!

Some initial comments:

  • You use UoM for some of the Channels like runtime. I would have expected Battery Charge to be a Number:Dimensionless using %, similar to the way one sees with humidity in some of the weather bindings. Dimmer carries along with is a bunch of extra stuff like the ability to act like a Switch and such which do not make sense for a sensor reading like this.

  • There should be a change of name or further description to distinguish between the Ups Status Channel (networkupstools:ups:nut:upsStatus) and Ups Status Channel (networkupstools:ups:nut:upsStatusText).

  • After creating some Items to link to some of the channels I see the following exceptions in the log.

2019-10-02 09:58:26.185 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'ups.items'
2019-10-02 09:59:27.038 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-10-02 10:01:31.505 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-10-02 10:02:32.086 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-10-02 10:03:34.560 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-10-02 10:04:36.586 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-10-02 10:05:37.135 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
2019-10-02 10:07:41.646 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occurred while informing handler: null
java.lang.NullPointerException: null
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.loginIfNeeded(NutConnector.java:76) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutConnector.read(NutConnector.java:57) ~[?:?]
        at org.openhab.binding.networkupstools.internal.nut.NutApi.getVariables(NutApi.java:53) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.refreshDevice(NetworkUPSToolsHandler.java:181) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.refreshValue(ExpiringCache.java:97) ~[?:?]
        at org.eclipse.smarthome.core.cache.ExpiringCache.getValue(ExpiringCache.java:68) ~[?:?]
        at org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandler.handleCommand(NetworkUPSToolsHandler.java:94) ~[?:?]
        at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.channelLinked(BaseThingHandler.java:203) ~[?:?]
        at org.eclipse.smarthome.core.thing.link.ThingLinkManager.lambda$0(ThingLinkManager.java:266) ~[?:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]

Items:

Dimmer vUPS2_Charge " UPS Level [%d%%]"
    <battery>
    { channel="networkupstools:ups:nut:batteryCharge" }

Dimmer vUPS2_Load "UPS Load [%d%%]"
    <battery>
    { channel="networkupstools:ups:nut:inputLoad" }

Number:Time vUPS2_Runtime "UPS Runtime [%s]"
    <time>
    { channel="networkupstools:ups:nut:batteryRuntime" }

String vUPS2_Alarm "UPS Alarm [%s]"
    <battery>
    { channel="networkupstools:ups:nut:upsAlarm" }

String vUPS2_Status "UPS Status [%s]"
    <battery>
    { channel="networkupstools:ups:nut:upsStatus" }

String vUPS2_Status_Str "UPS Status Str [%s]"
    <battery>
    { channel="networkupstools:ups:nut:upsStatusText" }

Number:Temperature vUPS2_Temp "UPS Temperature [%f °F]"
    <temperature>
    { channel="networkupstools:ups:nut:upsTemperature" }

The Items are not being updated.

I tried to put the binding into trace logging using the following config but the log file remains empty.

# NUT
log4j2.logger.nut.name = org.openhab.binding.networkupstools
log4j2.logger.nut.level = INFO
log4j2.logger.nut.additivity = false
log4j2.logger.nut.appenderRefs = NUT
log4j2.logger.nut.appenderRef.NUT.ref = NUT

log4j2.appender.nut.name = NUT
log4j2.appender.nut.type = RollingRandomAccessFile
log4j2.appender.nut.fileName = ${openhab.logdir}/nut.log
log4j2.appender.nut.filePattern = ${openhab.logdir}/nut.log.%i
log4j2.appender.nut.immediateFlush = true
log4j2.appender.nut.append = true
log4j2.appender.nut.layout.type = PatternLayout
log4j2.appender.nut.layout.pattern = %d{dd-MMM-yyyy HH:mm:ss.SSS} [%-5.5p] [%-50.50c] - %m%n
log4j2.appender.nut.policies.type = Policies
log4j2.appender.nut.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.nut.policies.size.size = 10MB
log4j2.appender.nut.strategy.type = DefaultRolloverStrategy
log4j2.appender.nut.strategy.max = 10

That’s all I have time for right this moment. I’ll pick it up later and report anything new that I find.

1 Like

If I understand correctly, I think this is an excellent solution to how many channels there are. In other words, common channels are provided and any additional channels beyond the common ones can be added by the user?

will test soon

I’ve created a new build with some changes/fixes. (version: Alpha 02/10/2019 20:45)

Changed Dimmer channels to Number:Dimensionless

I’ve changed the upsStatus to a channel with options and removed the upsStatusText channel. The upsStatus (e.g. Online) channel will now show the full text as text, and use the short text (e.g. OL) as value.

This should be fixed. I think I misinterpreted some code, so the call to the command was not send directly.

EDIT: I may have messed up. A noticed that my newly created Things were still using Dimmers for the load intsead of Number:Dimensionless. Turned out I still had the old binding hanging around. I’ll post another reply shortly after I get a chance to test it out again, now with only one copy of the latest binding running.

I had a few minutes so I tried the latest version.

I removed the old Thing, stopped OH, cleared the cache, downloaded the new version and recreated the Thing.

  • During startup I’m seeing some new exceptions. In my nut.log I’m seeing:
20│02-Oct-2019 14:38:22.422 [WARN ] [org.openhab.binding.networkupstools               ] - FrameworkEvent WARNING - org.openhab.binding.networkupstools                                                                   │
20│org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object                                                                              │
20│        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232) ~[?:?]                                                                                            │
20│        at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]                                                                                                   │
20│        at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]                                                                                                      │
20│        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]                                                                                       │
20│        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]                                                                                                       │
20│        at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]                                                                                                         │
20│        at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86) ~[?:?]                                                                                                              │
20│        at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) ~[?:?]                                                                                                             │
20│        at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664) ~[?:?]                                                                                                            │
20│        at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308) ~[?:?]                                                                                                    │
20│        at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1805) ~[?:?]                                                                                                  │
20│        at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1788) ~[?:?]                                                                                                    │
20│        at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:435) ~[?:?]                                                                                           │
20│        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:325) ~[?:?]                                                                               │
20│        at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:294) ~[?:?]                                                                               │
20│        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) ~[?:?]                                                                                                   │
20│        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) ~[?:?]                                                                                                   │
20│        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) ~[?:?]                                                                                                │
20│        at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) ~[?:?]                                                                                                      │
20│        at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) ~[?:?]                                                                                                    │
20│        at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) ~[?:?]                                                                                    │
20│        at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]                                                                                   │
00│        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]                                                                                                      │05  │        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]                                                                                                                │
  │        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]                                                                                                   │
  │        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]                                                                                    │
  │        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]                                                                                              │
  │        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]                                                                                         │
  │        at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]                                                                                                  │
  │        at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]                                                                                                    │
  │        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:906) ~[?:?]                                                                                             │
  │        at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892) ~[?:?]                                                                                             │
  │        at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]                                                                                               │
  │        at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959) ~[?:?]                                                                                        │
  │        at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732) ~[?:?]                                                                                       │
  │        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666) ~[?:?]                                                                                         │
  │        at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432) ~[?:?]                                                                                                 │
  │        at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]                                                                                 │
  │        at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338) ~[?:?]                                                                                                  │
  │        at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382) ~[?:?]                                                                                                                               │
  │        at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]                                                                                                                                    │
  │        at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264) ~[?:?]                                                                                                                           │
  │        at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]                                                                                                                │
  │        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]                                                                                                                 │
  │        at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]                                                                                                                  │
  │        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]                                                                                                               │
  │        at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]                                                                                                               │
  │        at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]                                                                                                                                │
  │        at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
20│        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]                                                                                                       │
20│        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]                                                                                                                │
20│        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]                                                                                                   │
20│        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]                                                                               │
20│        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]                                                                                         │
20│        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]                                                                                         │
20│        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]                                                                                     │
20│        at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]                                                                                                                                      │
20│        at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]                                                                                                                                             │
20│        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) ~[?:?]                                                                                              │
00│        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) ~[?:?]                                                                                              │24
  │        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) ~[?:?]                                                                                      │
  │        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) ~[?:?]                                                                                              │
  │        at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[?:?]                                                                                                 │
  │        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]                                                                                                                 │
  │        at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]

This warning appears a few times at startup.

In openhab.log I’m seeing some jetty exceptions which I think are unrelated but mention them just in case they may be relevant.

  • When I go to create the new Thing, there are two shown in PaperUI.

There is no apparent difference between the two. I chose the first one.

The Thing remains in the “UNKNOWN” state after I created it. I restarted OH and Thing eventually showed as ONLINE in PaperUI. But the linked Items remain NULL, never getting updated. There is nothing in nut.log except for the stack traces and warning logs above.

One thing that may be worth mentioning in case it’s relevant.

To see what would happen, I linked an Item to the Ups Temperature Channel but NUT does not report that value for my battery. I removed that Item and restarted OH. No difference from how it starts when the Item is there.

I repeated the above steps with a Thing created with the second choice and there was no difference.

1 Like

It’s strange you can choose 2 new things in PaperUI. It almost looks some kind of caching problem. The errors don’t seem to be related to the binding specifically, but also look to indicate on some kind of caching problem.

I’ve update the binding jar (date: 03/10/2019). And added more logging (both at debug and trace level). I’ve also changed that if a channel is linked, but no data is available it will just log about it, instead of throwing an exception (The exception would also not update any other channels).

OK, here are my updated results.

To deal with the issue I somehow caused before I uninstalled both instances of the binding bundle through the karaf console. I removed the NUT Thing, shutdown OH and cleared the cache.

I redownloaded the latest jar file which shows version 2.5.0.201910021839 in the console and only that one which is listed once.

When I started OH there were no exceptions any longer. Similarly there were no exceptions in the nut.log. In fact, throughout my tests there was nothing written to nut.log at all. I’ve looked and I don’t see an error in my log4j2 config, and I did get those exceptions in the log before, but perhaps there is something wrong?

There is now only the one Thing listed in PaperUI.

image

After creating the Thing it remained in the UNKNOWN state for a few minutes and eventually went to ONLINE. The Items change from NULL to UNDEF shortly after the Link events when watching events.log.

2019-10-03 09:27:34.843 [temChannelLinkRemovedEvent] - Link 'vUPS2_Status => networkupstools:ups:nut:upsStatus' has been removed.
2019-10-03 09:27:34.850 [temChannelLinkRemovedEvent] - Link 'vUPS2_Status_Str => networkupstools:ups:nut:upsStatusText' has been removed.
2019-10-03 09:27:34.857 [temChannelLinkRemovedEvent] - Link 'vUPS2_Alarm => networkupstools:ups:nut:upsAlarm' has been removed.
2019-10-03 09:27:34.876 [temChannelLinkRemovedEvent] - Link 'vUPS2_Load => networkupstools:ups:nut:inputLoad' has been removed.
2019-10-03 09:27:34.876 [temChannelLinkRemovedEvent] - Link 'vUPS2_Runtime => networkupstools:ups:nut:batteryRuntime' has been removed.
2019-10-03 09:27:34.879 [temChannelLinkRemovedEvent] - Link 'vUPS2_Charge => networkupstools:ups:nut:batteryCharge' has been removed.
2019-10-03 09:30:01.293 [vent.ItemStateChangedEvent] - vUPS2_Charge changed from NULL to UNDEF
2019-10-03 09:30:01.299 [vent.ItemStateChangedEvent] - vUPS2_Runtime changed from NULL to UNDEF
2019-10-03 09:30:01.311 [vent.ItemStateChangedEvent] - vUPS2_Load changed from NULL to UNDEF
2019-10-03 09:30:01.313 [vent.ItemStateChangedEvent] - vUPS2_Alarm changed from NULL to UNDEF
2019-10-03 09:30:01.315 [vent.ItemStateChangedEvent] - vUPS2_Status changed from NULL to UNDEF

I removed my custom logging config (see above) and restarted OH just to see if I messed up the binding’s logger somehow.

I’ll play around with the logger config to see if I can get more information. But this seems to be progress. I’m seeing what I expect (except for logging).

EDIT: I replaced my logger config with just:

log4j2.logger.nut.name = org.openhab.binding.networkupstools
log4j2.logger.nut.level = TRACE

And I now see just a handful of logging statements from the binding in the log.

--------------------Shutdown of OH---------------------
20│2019-10-03 09:46:35.837 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=340, service.bundleid=203, service.sco│
20│pe=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandlerFactory, component.id=193} - org.openhab.binding.networkupstools                                                          │
20│2019-10-03 09:46:35.839 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent UNREGISTERING - {org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, org.eclipse.smarthome.core.thing.typ│
20│e.ChannelTypeProvider}={service.id=339, service.bundleid=203, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, component.id=192} - org.openhab.binding.│
20│networkupstools                                                                                                                                                                                                        │
20│2019-10-03 09:46:35.843 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STOPPING - org.openhab.binding.networkupstools                                                                                    │
20│2019-10-03 09:46:35.846 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STOPPED - org.openhab.binding.networkupstools

--------------------Startup of OH---------------------
2019-10-03 09:47:00.547 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTING - org.openhab.binding.networkupstools                                                                                    │
20│2019-10-03 09:47:00.551 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, org.eclipse.smarthome.core.thing.type.C│
20│hannelTypeProvider}={service.id=339, service.bundleid=203, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, component.id=192} - org.openhab.binding.net│
20│workupstools                                                                                                                                                                                                           │
20│2019-10-03 09:47:00.569 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=340, service.bundleid=203, service.scope=│
20│bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandlerFactory, component.id=193} - org.openhab.binding.networkupstools                                                             │
  │2019-10-03 09:47:00.573 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTED - org.openhab.binding.networkupstools

There are no other logging statements from the binding.

1 Like

Thanks for your extensive testing so far. I’ve updated the jar with a new version (30/10/2019). It should contain much more logging and a fix. Can you try the new version?

Just installed:
image

I created my UPS thing from the paper UI. Two minutes after, it appears to be online. I assume, that the communication (and authentication) to the NUT server is working. Til now, none of the channels get updatet yet:

2019-10-03 18:51:57.084 [hingStatusInfoChangedEvent] - 'networkupstools:ups:f4be22e2' changed from UNINITIALIZED to INITIALIZING

2019-10-03 18:51:57.122 [hingStatusInfoChangedEvent] - 'networkupstools:ups:f4be22e2' changed from INITIALIZING to UNKNOWN

2019-10-03 18:51:57.159 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_batteryCharge-networkupstools:ups:f4be22e2:batteryCharge' has been added.

2019-10-03 18:51:57.169 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_batteryRuntime-networkupstools:ups:f4be22e2:batteryRuntime' has been added.

2019-10-03 18:51:57.186 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_inputLoad-networkupstools:ups:f4be22e2:inputLoad' has been added.

2019-10-03 18:51:57.197 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_inputVoltage-networkupstools:ups:f4be22e2:inputVoltage' has been added.

2019-10-03 18:51:57.207 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_upsAlarm-networkupstools:ups:f4be22e2:upsAlarm' has been added.

2019-10-03 18:51:57.221 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_upsRealpower-networkupstools:ups:f4be22e2:upsRealpower' has been added.

2019-10-03 18:51:57.350 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_upsStatus-networkupstools:ups:f4be22e2:upsStatus' has been added.

2019-10-03 18:51:57.359 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_upsTemperature-networkupstools:ups:f4be22e2:upsTemperature' has been added.

2019-10-03 18:52:11.539 [temChannelLinkRemovedEvent] - Link 'networkupstools_ups_f4be22e2_batteryCharge => networkupstools:ups:f4be22e2:batteryCharge' has been removed.

2019-10-03 18:52:12.432 [.ItemChannelLinkAddedEvent] - Link 'networkupstools_ups_f4be22e2_batteryCharge-networkupstools:ups:f4be22e2:batteryCharge' has been added.

2019-10-03 18:52:58.203 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_batteryCharge changed from NULL to UNDEF

2019-10-03 18:54:00.314 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_inputLoad changed from NULL to UNDEF

2019-10-03 18:54:00.323 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_batteryRuntime changed from NULL to UNDEF

2019-10-03 18:54:00.334 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsAlarm changed from NULL to UNDEF

2019-10-03 18:54:00.342 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsRealpower changed from NULL to UNDEF

2019-10-03 18:54:00.349 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsStatus changed from NULL to UNDEF

2019-10-03 18:54:00.359 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_inputVoltage changed from NULL to UNDEF

2019-10-03 18:54:00.370 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsTemperature changed from NULL to UNDEF

2019-10-03 18:54:00.377 [hingStatusInfoChangedEvent] - 'networkupstools:ups:f4be22e2' changed from UNKNOWN to ONLINE
1 Like

@curlyel Can you run with log level trace? (log:set TRACE org.openhab.binding.networkupstools). I suspect the data isn’t correctly read from the nut server.

Sure:

2019-10-03 19:11:57.174 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTING - org.openhab.binding.networkupstools

2019-10-03 19:11:57.804 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, org.eclipse.smarthome.core.thing.type.ChannelTypeProvider}={service.id=456, service.bundleid=262, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, component.id=294} - org.openhab.binding.networkupstools

2019-10-03 19:11:58.000 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=457, service.bundleid=262, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandlerFactory, component.id=295} - org.openhab.binding.networkupstools

2019-10-03 19:11:58.118 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTED - org.openhab.binding.networkupstools

2019-10-03 19:11:58.529 [hingStatusInfoChangedEvent] - 'networkupstools:ups:f4be22e2' changed from UNINITIALIZED to INITIALIZING

2019-10-03 19:11:58.696 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.698 [hingStatusInfoChangedEvent] - 'networkupstools:ups:f4be22e2' changed from INITIALIZING to UNKNOWN

2019-10-03 19:11:58.701 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.713 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.740 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.744 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.756 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.760 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.765 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.769 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.773 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:11:58.777 [TRACE] [ools.internal.NetworkUPSToolsHandler] - No data from NUT server received.

2019-10-03 19:12:58.783 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:12:58.800 [TRACE] [kupstools.internal.nut.NutListParser] - Reading VAR usv

2019-10-03 19:13:59.227 [TRACE] [kupstools.internal.nut.NutListParser] - Begin of list 'VAR usv' found

2019-10-03 19:13:59.232 [TRACE] [kupstools.internal.nut.NutListParser] - List 'VAR usv' read. 0 variables read

2019-10-03 19:13:59.235 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Updating status of linked channels.

2019-10-03 19:13:59.257 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_batteryCharge changed from NULL to UNDEF

2019-10-03 19:13:59.276 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_batteryRuntime changed from NULL to UNDEF

2019-10-03 19:13:59.281 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_inputLoad changed from NULL to UNDEF

2019-10-03 19:13:59.286 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_inputVoltage changed from NULL to UNDEF

2019-10-03 19:13:59.289 [hingStatusInfoChangedEvent] - 'networkupstools:ups:f4be22e2' changed from UNKNOWN to ONLINE

2019-10-03 19:13:59.292 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsAlarm changed from NULL to UNDEF

2019-10-03 19:13:59.295 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsRealpower changed from NULL to UNDEF

2019-10-03 19:13:59.298 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsStatus changed from NULL to UNDEF

2019-10-03 19:13:59.301 [vent.ItemStateChangedEvent] - networkupstools_ups_f4be22e2_upsTemperature changed from NULL to UNDEF

2019-10-03 19:14:59.271 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:14:59.276 [TRACE] [kupstools.internal.nut.NutListParser] - Reading VAR usv

2019-10-03 19:16:01.471 [TRACE] [kupstools.internal.nut.NutListParser] - Begin of list 'VAR usv' found

2019-10-03 19:16:01.475 [TRACE] [kupstools.internal.nut.NutListParser] - List 'VAR usv' read. 0 variables read

2019-10-03 19:16:01.478 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Updating status of linked channels.

2019-10-03 19:17:01.495 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.

2019-10-03 19:17:01.500 [TRACE] [kupstools.internal.nut.NutListParser] - Reading VAR usv
1 Like

I’ve tried without authenthication (empty user/password), which is working with NUT1-binding. Still no channels get updated.

When trying upsc, it provides these values:

openHAB4-USV:/etc/openhab2/things# upsc usv@localhost:3493
Init SSL without certificate database
battery.charge: 100
battery.charge.low: 10
battery.charge.warning: 50
battery.runtime: 5640
battery.runtime.low: 120
battery.type: PbAc
battery.voltage: 27.3
battery.voltage.nominal: 24.0
device.mfr: American Power Conversion
device.model: Smart-UPS C 1500
device.serial: <cleared>
device.type: ups
driver.name: usbhid-ups
driver.parameter.pollfreq: 30
driver.parameter.pollinterval: 2
driver.parameter.port: auto
driver.parameter.synchronous: no
driver.version: 2.7.4
driver.version.data: APC HID 0.96
driver.version.internal: 0.41
ups.beeper.status: disabled
ups.delay.shutdown: 20
ups.firmware: UPS 10.0 / ID=1005
ups.mfr: American Power Conversion
ups.mfr.date: <cleared>
ups.model: Smart-UPS C 1500
ups.productid: 0003
ups.serial: <cleared>
ups.status: OL
ups.timer.reboot: -1
ups.timer.shutdown: -1
ups.vendorid: 051d
1 Like

Hmm. It looks like it’s not reading anything. I’ve changed the reading part and added some more logging. Binding version: (03/10/2019 21:00) Could you try the new version?

I followed the usual steps.

  1. removed the old Thing.
  2. bundle:uninstall the old binding
  3. stop openHAB
  4. clear the cache
  5. downloaded the latest jar file
  6. restarted OH (twice, it always takes two restarts after a clear the cache for some reason)
  7. Verified I’m running the latest version (2.5.0.201910031905)
  8. recreated the Thing (I keep the same Thing name so my Links remain valid.

I left my log4j2 config for this binding as above, just with it being in TRACE logging level as shown above.

The following is what I see in the logs from the binding:

-----------------------When OH comes up----------------
  │2019-10-03 16:10:29.599 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTING - org.openhab.binding.networkupstools                                                                                    │
  │2019-10-03 16:10:29.617 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTED - org.openhab.binding.networkupstools                                                                                     │
  │2019-10-03 16:10:29.620 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, org.eclipse.smarthome.core.thing.type.C│
  │hannelTypeProvider}={service.id=339, service.bundleid=203, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, component.id=192} - org.openhab.binding.net│
  │workupstools                                                                                                                                                                                                           │
  │2019-10-03 16:10:29.630 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=340, service.bundleid=203, service.scope=│
  │bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandlerFactory, component.id=193} - org.openhab.binding.networkupstools

--------------------------Created the Thing--------------------------------
  │2019-10-03 16:15:04.391 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
  │2019-10-03 16:15:04.393 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
  │2019-10-03 16:15:04.394 [TRACE] [ools.internal.NetworkUPSToolsHandler] - No data from NUT server received.                                                                                                             │
  │2019-10-03 16:15:04.396 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.
2019-10-03 16:15:04.402 [TRACE] [kupstools.internal.nut.NutListParser] - Reading VAR ups                                                                                                                               │
20│2019-10-03 16:15:04.404 [TRACE] [kupstools.internal.nut.NutListParser] - Line read:ERR INVALID-ARGUMENT

---------------------------------------events.log after creating the Thing------------------------
2019-10-03 16:15:04.310 [hingStatusInfoChangedEvent] - 'networkupstools:ups:nut' changed from UNINITIALIZED to INITIALIZING                                                                                            │
  │2019-10-03 16:15:04.405 [hingStatusInfoChangedEvent] - 'networkupstools:ups:nut' changed from INITIALIZING to UNKNOWN

The Thing remained in the UNKNOWN state for about ten minutes. I restarted OH to see what would happen. The logs are different but not very illuminating:

20│2019-10-03 16:27:09.377 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTING - org.openhab.binding.networkupstools                                                                                    │
20│2019-10-03 16:27:09.380 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTED - org.openhab.binding.networkupstools                                                                                     │
20│2019-10-03 16:27:09.473 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, org.eclipse.smarthome.core.thing.type.C│
20│hannelTypeProvider}={service.id=339, service.bundleid=203, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, component.id=192} - org.openhab.binding.net│
20│workupstools                                                                                                                                                                                                           │
20│2019-10-03 16:27:09.479 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=340, service.bundleid=203, service.scope=│
20│bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandlerFactory, component.id=193} - org.openhab.binding.networkupstools                                                             │
20│2019-10-03 16:27:09.901 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.
2019-10-03 16:27:09.987 [TRACE] [kupstools.internal.nut.NutListParser] - Reading VAR ups                                                                                                                               │
20│2019-10-03 16:27:09.990 [TRACE] [kupstools.internal.nut.NutListParser] - Line read:ERR INVALID-ARGUMENTq
--------------------------events.log----------------------------
20│2019-10-03 16:27:09.800 [hingStatusInfoChangedEvent] - 'networkupstools:ups:nut' changed from UNINITIALIZED to INITIALIZING                                                                                            │
20│2019-10-03 16:27:09.816 [hingStatusInfoChangedEvent] - 'networkupstools:ups:nut' changed from INITIALIZING to UNKNOWN

The Thing remains in the UNKNOWN state.

I tried a different username just to see if it makes a difference (I have a few users defined from testing when I first set NUT up). I saw a Thing updated notification in the events.log but no further logs for several minutes. I tried restarting and saw the following logs:

20│2019-10-03 16:34:32.766 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTING - org.openhab.binding.networkupstools                                                                                    │
20│2019-10-03 16:34:32.769 [DEBUG] [org.openhab.binding.networkupstools ] - BundleEvent STARTED - org.openhab.binding.networkupstools                                                                                     │
20│2019-10-03 16:34:32.775 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, org.eclipse.smarthome.core.thing.type.C│
20│hannelTypeProvider}={service.id=339, service.bundleid=203, service.scope=bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSChannelTypeProvider, component.id=192} - org.openhab.binding.net│
00│workupstools                                                                                                                                                                                                           │28
20│2019-10-03 16:34:32.784 [DEBUG] [org.openhab.binding.networkupstools ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.core.thing.binding.ThingHandlerFactory}={service.id=340, service.bundleid=203, service.scope=│
20│bundle, component.name=org.openhab.binding.networkupstools.internal.NetworkUPSToolsHandlerFactory, component.id=193} - org.openhab.binding.networkupstools                                                             │
20│2019-10-03 16:34:33.229 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
20│2019-10-03 16:34:33.231 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
20│2019-10-03 16:34:33.233 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
20│2019-10-03 16:34:33.235 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
20│2019-10-03 16:34:33.247 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.                                                                                                                 │
20│2019-10-03 16:34:33.278 [TRACE] [ools.internal.NetworkUPSToolsHandler] - Get new data from NUT server.
2019-10-03 16:34:33.315 [TRACE] [kupstools.internal.nut.NutListParser] - Reading VAR ups                                                                                                                               │
20│2019-10-03 16:34:33.320 [TRACE] [kupstools.internal.nut.NutListParser] - Line read:ERR INVALID-ARGUMENT

This is starting to look like progress. It seems to get stuck as soon as it encounters that ERR INVALID ARGUMENT.

1 Like