OpenRemote stops showing actual VERA device statuses after few days

Hello everyone,

I’m an OpenRemote user for two years. My controller has run without problems for another half year, but now I have the following issue again.

One or two days after a restart of my RaspberryPi running OpenRemote the console Apps stops showing the actual status of my VERA devices. For example: once I switch a device to ON it actually switches to ON but the status in OR remains OFF, so after that I can’t use OR to switch the device OFF again.

In the OR logs folder I see a file called vera.log. The file change date is updated each time I toggle a device but the file contents doesn’t change, while normally it shows the data that was received from VERA like the device statuses.

Can anyone give me a solution or direction on how to find and resolve this issue?

Best regards,
Dirk-Jan

Did you change your network config? Maybe VERA received a new IP address or the Pi and VERA cannot communicate with each other?

Hi Marcus, thanks, no I have given my RaspberryPi a static IP address.

I assume the VERA has static IP also. Can you ping VERA from the Pi?
Do you see anything in the other log files from OR controller?

Yes from out the Raspberry I can ping the VERA successful. Also OR can still switch on lights by the VERA. Maybe also handy to mention is that I had created a HTTP device in OR to control the privacy mode of my webcam. When I use the OR app to change the status the changed status is correctly shown in the App, so the problem is only with the VERA.

I see the following error reoccurring in the boot.log:

TRACE 2016-11-06 14:42:34,712 : Unable to retrieve controller identity
org.openremote.controller.exception.ConnectionException: The required password for user ‘dirk.jan.hoekstra’ was not found. Password manager error : Password for user ‘org.openremote.security.PasswordManager$PasswordNotFoundException: Implementation Error: password alias ‘dirk.jan.hoekstra’ does not correspond to secret key entry in the keystore.’ was not found
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.connect(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.httpRequest(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.httpPost(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.getControllerIdentity(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.getRemoteCommandService(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.openremote.controller.service.Deployer$PasswordException: Password for user ‘org.openremote.security.PasswordManager$PasswordNotFoundException: Implementation Error: password alias ‘dirk.jan.hoekstra’ does not correspond to secret key entry in the keystore.’ was not found
at org.openremote.controller.service.Deployer.getPassword(Unknown Source)

And I see the following error in the dev.log. For my thermostat devices I use a HTTP sensor in OR to get their status ouf of the VERA:

2016-11-06 07:05:32,689 ERROR [Polling Sensor Thread ID = 311692, Name =‘072_SETPOINT_SENSOR’]: IOException when executing HTTP method
org.apache.http.NoHttpResponseException: The target server failed to respond

And also the password error is this dev.log:

2016-11-06 06:53:18,276 ERROR [DiscoveredDevicesAnnouncement]: Could not announce discovered devices
org.openremote.controller.service.Deployer$PasswordException: Password for user ‘org.openremote.security.PasswordManager$PasswordNotFoundException: Implementation Error: password alias ‘dirk.jan.hoekstra’ does not correspond to secret key entry in the keystore.’ was not found
at org.openremote.controller.service.Deployer.getPassword(Unknown Source)
at org.openremote.controller.service.Deployer$DiscoveredDevicesAnnouncement.run(Unknown Source)

And the sensor.log is full with this error:
WARN 2016-11-06 15:03:18,129 : Event producer bound to sensor (ID = 313,283) returned a value that is not consistent with sensor’s datatype : 0 setting sensor value to ‘N/A’
WARN 2016-11-06 15:03:28,173 : Event producer bound to sensor (ID = 313,283) returned a value that is not consistent with sensor’s datatype : 0 setting sensor value to ‘N/A’
WARN 2016-11-06 15:03:38,212 : Event producer bound to sensor (ID = 313,283) returned a value that is not consistent with sensor’s datatype : 0 setting sensor value to ‘N/A’

And in the dsc-debug.log it says:
DEBUG 2016-10-20 08:04:08,466 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-10-23 23:26:19,591 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-10-26 08:12:44,739 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-10-30 10:39:13,732 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-11-05 12:10:55,318 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.

I didn’t kept the exact time but at least the last error is close to the moment when the problem of no status updates started.

And the http.log doesn’t show errors.

Further more I could not find any logs with change date of yesterday or today.

The password error does not have anything todo with it.
But the HTTP Response Error seems to be the problem. The VERA does not answer.
Did you change the VERA firmware or something else on the VERA?

Hello,

I have solved some errors in sensors I had created incorrect, so my sensor.log is seems no clean of errors.

But I still have the problem that OR don’t show or get the correct status of a switch after it was toggled. For example I switched the following switch from OFF to ON. In the vera.log I can see that OR sends a command to Vera and indeed the light goes on.

DEBUG 2016-11-11 20:34:37,499 (Vera): Updated generic sensor field ‘caid’ with value: 15996312
DEBUG 2016-11-11 20:43:29,902 (Vera): Building Vera command
DEBUG 2016-11-11 20:43:29,903 (Vera): Vera command: deviceId = 35
DEBUG 2016-11-11 20:43:29,903 (Vera): Vera command: command = ON
DEBUG 2016-11-11 20:43:29,904 (Vera): Vera command created successfully
DEBUG 2016-11-11 20:43:29,904 (Vera): Sending Vera command: http://192.168.1.100:3480/data_request?id=lu_action&output_format=xml&DeviceNum=35&serviceId=urn:upnp-org:serviceId:SwitchPower1&action=SetTarget&newTargetValue=1
DEBUG 2016-11-11 20:43:29,921 (Vera): Received: <?xml version="1.0"?>
<u:SetTargetResponse xmlns:u=“urn:schemas-upnp-org:service:SwitchPower:1”>
376
</u:SetTargetResponse>

But because in the OR console the switch status remains OFF - the next time I press on the switch OR sends the ON command again while I need it to send a OFF command:

DEBUG 2016-11-11 20:45:09,635 (Vera): Building Vera command
DEBUG 2016-11-11 20:45:09,636 (Vera): Vera command: deviceId = 35
DEBUG 2016-11-11 20:45:09,636 (Vera): Vera command: command = ON
DEBUG 2016-11-11 20:45:09,637 (Vera): Vera command created successfully
DEBUG 2016-11-11 20:45:09,638 (Vera): Sending Vera command: http://192.168.1.100:3480/data_request?id=lu_action&output_format=xml&DeviceNum=35&serviceId=urn:upnp-org:serviceId:SwitchPower1&action=SetTarget&newTargetValue=1
DEBUG 2016-11-11 20:45:09,658 (Vera): Received: <?xml version="1.0"?>
<u:SetTargetResponse xmlns:u=“urn:schemas-upnp-org:service:SwitchPower:1”>
377
</u:SetTargetResponse>

Yesterday installed OR 2.6 Alpha but the problem remained
Today Raspbian Jessie with PIXEL (release date 2016-09-23) on my Raspberry Pi and just used the JAVA version that comes with it and installed OR 2.6 Alpha again. Now testing to see what comes out of this…

Yesterday installed OR 2.6 Alpha but the problem remained
Today Raspbian Jessie with PIXEL (release date 2016-09-23) on my Raspberry Pi and just used the JAVA version that comes with it and installed OR 2.6 Alpha again. Now testing to see what comes out of this…

The password error does not have anything todo with it.
But the HTTP Response Error seems to be the problem. The VERA does not answer.
Did you change the VERA firmware or something else on the VERA?

I assume the VERA has static IP also. Can you ping VERA from the Pi?
Do you see anything in the other log files from OR controller?

Hi Marcus, thanks, no I have given my RaspberryPi a static IP address.

Did you change your network config? Maybe VERA received a new IP address or the Pi and VERA cannot communicate with each other?

Hello everyone,

I’m an OpenRemote user for two years. My controller has run without problems for another half year, but now I have the following issue again.

One or two days after a restart of my RaspberryPi running OpenRemote the console Apps stops showing the actual status of my VERA devices. For example: once I switch a device to ON it actually switches to ON but the status in OR remains OFF, so after that I can’t use OR to switch the device OFF again.

In the OR logs folder I see a file called vera.log. The file change date is updated each time I toggle a device but the file contents doesn’t change, while normally it shows the data that was received from VERA like the device statuses.

Can anyone give me a solution or direction on how to find and resolve this issue?

Best regards,
Dirk-Jan

Yes from out the Raspberry I can ping the VERA successful. Also OR can still switch on lights by the VERA. Maybe also handy to mention is that I had created a HTTP device in OR to control the privacy mode of my webcam. When I use the OR app to change the status the changed status is correctly shown in the App, so the problem is only with the VERA.

I see the following error reoccurring in the boot.log:

TRACE 2016-11-06 14:42:34,712 : Unable to retrieve controller identity
org.openremote.controller.exception.ConnectionException: The required password for user ‘dirk.jan.hoekstra’ was not found. Password manager error : Password for user ‘org.openremote.security.PasswordManager$PasswordNotFoundException: Implementation Error: password alias ‘dirk.jan.hoekstra’ does not correspond to secret key entry in the keystore.’ was not found
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.connect(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.httpRequest(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.httpPost(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.getControllerIdentity(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.getRemoteCommandService(Unknown Source)
at org.openremote.controller.service.BeehiveCommandCheckService$BeehiveCommandChecker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.openremote.controller.service.Deployer$PasswordException: Password for user ‘org.openremote.security.PasswordManager$PasswordNotFoundException: Implementation Error: password alias ‘dirk.jan.hoekstra’ does not correspond to secret key entry in the keystore.’ was not found
at org.openremote.controller.service.Deployer.getPassword(Unknown Source)

And I see the following error in the dev.log. For my thermostat devices I use a HTTP sensor in OR to get their status ouf of the VERA:

2016-11-06 07:05:32,689 ERROR [Polling Sensor Thread ID = 311692, Name =‘072_SETPOINT_SENSOR’]: IOException when executing HTTP method
org.apache.http.NoHttpResponseException: The target server failed to respond

And also the password error is this dev.log:

2016-11-06 06:53:18,276 ERROR [DiscoveredDevicesAnnouncement]: Could not announce discovered devices
org.openremote.controller.service.Deployer$PasswordException: Password for user ‘org.openremote.security.PasswordManager$PasswordNotFoundException: Implementation Error: password alias ‘dirk.jan.hoekstra’ does not correspond to secret key entry in the keystore.’ was not found
at org.openremote.controller.service.Deployer.getPassword(Unknown Source)
at org.openremote.controller.service.Deployer$DiscoveredDevicesAnnouncement.run(Unknown Source)

And the sensor.log is full with this error:
WARN 2016-11-06 15:03:18,129 : Event producer bound to sensor (ID = 313,283) returned a value that is not consistent with sensor’s datatype : 0 setting sensor value to ‘N/A’
WARN 2016-11-06 15:03:28,173 : Event producer bound to sensor (ID = 313,283) returned a value that is not consistent with sensor’s datatype : 0 setting sensor value to ‘N/A’
WARN 2016-11-06 15:03:38,212 : Event producer bound to sensor (ID = 313,283) returned a value that is not consistent with sensor’s datatype : 0 setting sensor value to ‘N/A’

And in the dsc-debug.log it says:
DEBUG 2016-10-20 08:04:08,466 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-10-23 23:26:19,591 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-10-26 08:12:44,739 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-10-30 10:39:13,732 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.
DEBUG 2016-11-05 12:10:55,318 (DSC): Adding shutdown hook to manage unclosed DSC connections in case of controller exit.

I didn’t kept the exact time but at least the last error is close to the moment when the problem of no status updates started.

And the http.log doesn’t show errors.

Further more I could not find any logs with change date of yesterday or today.

Hello,

I have solved some errors in sensors I had created incorrect, so my sensor.log is seems no clean of errors.

But I still have the problem that OR don’t show or get the correct status of a switch after it was toggled. For example I switched the following switch from OFF to ON. In the vera.log I can see that OR sends a command to Vera and indeed the light goes on.

DEBUG 2016-11-11 20:34:37,499 (Vera): Updated generic sensor field ‘caid’ with value: 15996312
DEBUG 2016-11-11 20:43:29,902 (Vera): Building Vera command
DEBUG 2016-11-11 20:43:29,903 (Vera): Vera command: deviceId = 35
DEBUG 2016-11-11 20:43:29,903 (Vera): Vera command: command = ON
DEBUG 2016-11-11 20:43:29,904 (Vera): Vera command created successfully
DEBUG 2016-11-11 20:43:29,904 (Vera): Sending Vera command: http://192.168.1.100:3480/data_request?id=lu_action&output_format=xml&DeviceNum=35&serviceId=urn:upnp-org:serviceId:SwitchPower1&action=SetTarget&newTargetValue=1
DEBUG 2016-11-11 20:43:29,921 (Vera): Received: <?xml version="1.0"?>
<u:SetTargetResponse xmlns:u=“urn:schemas-upnp-org:service:SwitchPower:1”>
376
</u:SetTargetResponse>

But because in the OR console the switch status remains OFF - the next time I press on the switch OR sends the ON command again while I need it to send a OFF command:

DEBUG 2016-11-11 20:45:09,635 (Vera): Building Vera command
DEBUG 2016-11-11 20:45:09,636 (Vera): Vera command: deviceId = 35
DEBUG 2016-11-11 20:45:09,636 (Vera): Vera command: command = ON
DEBUG 2016-11-11 20:45:09,637 (Vera): Vera command created successfully
DEBUG 2016-11-11 20:45:09,638 (Vera): Sending Vera command: http://192.168.1.100:3480/data_request?id=lu_action&output_format=xml&DeviceNum=35&serviceId=urn:upnp-org:serviceId:SwitchPower1&action=SetTarget&newTargetValue=1
DEBUG 2016-11-11 20:45:09,658 (Vera): Received: <?xml version="1.0"?>
<u:SetTargetResponse xmlns:u=“urn:schemas-upnp-org:service:SwitchPower:1”>
377
</u:SetTargetResponse>

All is still working with this new setup

Unfortunate the problem is not completely gone, it just takes longer before OR starts failing again and I need to reinstall my RPI en OR.