Piface 2 Troublshooting

Hello
I am trying to use openhab trigger a garage door opener on a Pi2 with the piface digital relay. It was working good whi UI it does not change he relay state although I can change the relay state from a python console. How would I begin troubleshooting this?

Im also seeing the following in /var/log/openhab/openhab.log
2015-11-21 17:44:24.917 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 3)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:24.920 [WARN ] [.piface.internal.PifaceBinding] - Command failed 3 times. Stopping.
2015-11-21 17:44:24.923 [WARN ] [.piface.internal.PifaceBinding] - Failed to initialise value for Piface pin 1 (pifaceid1): Command failed 3 times. Stopping.
2015-11-21 17:44:26.928 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 1)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:27.935 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 2)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:28.942 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 3)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:28.945 [WARN ] [.piface.internal.PifaceBinding] - Command failed 3 times. Stopping.
2015-11-21 17:44:28.948 [WARN ] [.piface.internal.PifaceBinding] - Failed to initialise value for Piface pin 1 (pifaceid1): Command failed 3 times. Stopping.
2015-11-21 17:44:30.954 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 1)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:31.962 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 2)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:32.969 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 3)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:32.973 [WARN ] [.piface.internal.PifaceBinding] - Command failed 3 times. Stopping.
2015-11-21 17:44:32.983 [WARN ] [.piface.internal.PifaceBinding] - Failed to initialise value for Piface pin 1 (pifaceid1): Command failed 3 times. Stopping.
2015-11-21 17:44:34.989 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 1)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:35.997 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 2)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:37.004 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 3)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:37.008 [WARN ] [.piface.internal.PifaceBinding] - Command failed 3 times. Stopping.
2015-11-21 17:44:37.011 [WARN ] [.piface.internal.PifaceBinding] - Failed to initialise value for Piface pin 1 (pifaceid1): Command failed 3 times. Stopping.
2015-11-21 17:44:39.016 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 1)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]
2015-11-21 17:44:40.022 [ERROR] [.piface.internal.PifaceBinding] - Failed to send command (3) to 10.0.0.100:15432 (attempt 2)
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:298) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendCommand(PifaceBinding.java:268) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.sendReadOutputPins(PifaceBinding.java:252) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding.access$6(PifaceBinding.java:251) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.initialiseBindingConfigs(PifaceBinding.java:570) [bundlefile:na]
at org.openhab.binding.piface.internal.PifaceBinding$PifaceInitialiser.run(PifaceBinding.java:536) [bundlefile:na]

The exception is showing that the binding is failing to issue the command.

The first thing I would check is permissions. Did you install openhab using apt-get? If so you need to update the service start script so openHAB will run as root. I don’t think openHAB can interact with the GPIO pins, even if it is through Pihat, as any other user and with an apt-get install openHAB runs as the openhab user.

Hi,

what do you mean with update the service start script, after apt-get install on a brand new raspi jessie installation openhab don’t start neither with sudo /etc/init.d/openhab start nor with sudo systemctl start openhab.

the result after sudo systemctl start openhab.

pi@raspberrypi:/etc/openhab/configurations $ sudo systemctl start openhab
pi@raspberrypi:/etc/openhab/configurations $

seems that openhab.cfg is ignored? I’m right?
Any ideas? Many thanks in advance

kind regards

Peter

First things first.[quote=“peterd, post:3, topic:4403”]
the result after sudo systemctl start openhab.

pi@raspberrypi:/etc/openhab/configurations $ sudo systemctl start openhabpi@raspberrypi:/etc/openhab/configurations $
[/quote]

That is what you should expect to see. When you run a program as a service it runs in the background. To see if it is actually running you can run systemctl status openhab.service and it will say “Active: active (running) since …” in the output if it is running.

Wrong. openhab.cfg is a configuration file that is ALWAYS loaded by openHAB when it starts and it has all of the necessary information needed by openHAB to configure itself and the installed bindings. However, all of this happens AFTER openHAB is started and has nothing to do with systemctl.

Now, if and only if you need to use the GPIO binding (or any other binding that requires root access, of which I am currently unaware of any) you will need to change the user under which openHAB runs.

If you want to see what the service is logging you need to find its log file. In openHAB’s case the file is located in /var/log/openhab/openhab.log. If you run tail -f /var/log/openhab/openhab.log you will see everything written to this file as it is written.

When you start openhab using system or systemctl you are executing the service’s start script.

On older systems it executes the script /etc/init.d/openhab and in that script there is a variable called “RUN_AS” where you can define which user openhab will run under. It should be set to “openhab”.

On newer systemd based systems, which jessie is, there is a file called openhab.service. There is more than one location it could be. On my systemd based Ubuntu it is located in /usr/lib/systemd/system/openhab.service. You can find out where it is by running systemctl status openhab and looking at the line that starts 'Loaded: loaded (. There is a section in this file called[Service]` that includes a “User” and “Group”. They will be set to “openhab” and if you plan on using the GPIO you need to set them both to “root”.

Hi,

many thanks. I checked the system using your hints and I find the following:

Loaded: loaded (/usr/lib/systemd/system/openhab.service; disabled) -< seems strange?

Serial Error: Port /dev/ttyAMA0 …not exist -> is new

ls /dev/tty* shows

/dev/ttyAMA0

User and Group is openhab

[Service]
EnvironmentFile=/etc/default/openhab
User=openhab
Group=openhab

my question: How do I set it root ???

I already did this: sudo usermod -a -G dialout openhab

Many thanks in advance …

-------------- more info below ------------------

openhab.service - Starts and stops the openHAB Home Automation Bus
Loaded: loaded (/usr/lib/systemd/system/openhab.service; disabled)
Active: active (running) since Di 2016-01-05 11:44:16 CET; 5min ago
Docs: http://www.openhab.org
Process: 936 ExecStartPre=/usr/share/openhab/bin/setpermissions.sh (code=exited, status=0/SUCCESS)
Main PID: 1101 (openhab.sh)
CGroup: /system.slice/openhab.service
├─1101 /bin/sh /usr/share/openhab/bin/openhab.sh -o
└─1131 /usr/bin/java -Dlogback.configurationFile=/etc/openhab/logback.xml -Dosgi.clean=true -Declipse.ignoreApp=true -Dosgi.noShutdown=true -Dj…

Jan 05 11:45:01 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:01.547 [INFO ] [.o.io.habmin.HABminApplication] - Started HABmin REST API at /services/habmin
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.743 [INFO ] [.z.internal.ZWaveActiveBinding] - Update config, port = /dev/ttyAMA0
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.747 [INFO ] [.z.internal.ZWaveActiveBinding] - Update config, healtime = 2
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.754 [INFO ] [.service.AbstractActiveService] - ZWave Refresh Service has been started
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.858 [INFO ] [b.z.i.protocol.ZWaveController] - Starting Z-Wave controller
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.860 [INFO ] [b.z.i.protocol.ZWaveController] - Z-Wave timeout is set to 5000ms…is false.
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.861 [INFO ] [b.z.i.protocol.ZWaveController] - Connecting to serial port /dev/ttyAMA0
Jan 05 11:45:06 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:06.959 [ERROR] [b.z.i.protocol.ZWaveController] - Serial Error: Port /dev/ttyAMA0 …not exist
Jan 05 11:45:11 raspberrypi openhab.sh[1101]: 2016-01-05 11:45:11.761 [INFO ] [.service.AbstractActiveService] - ZWave Refresh Service has been shut down
Jan 05 11:48:51 raspberrypi systemd[1]: Started Starts and stops the openHAB Home Automation Bus.
Hint: Some lines were ellipsized, use -l to show in full.

I think that may mean that openHAB is not set up to be run at boot. But I’m no expert, it could mean something else. On mine that line reads:

Loaded: loaded (/usr/lib/systemd/system/openhab.service; enabled; vendor preset: enabled)

This is almost certainly because the openhab user does not have permission to read/write to that device. Adding the openhab to the dialout group should have fixed this. Maybe try setting the permission on ttyAMA0 so everyone can read and write to it and seeing if the error goes away.

I suppose it also might be possible that some other process has a lock on that device. Are you running any other programs that may want to communicate to serial devices?

[Service]
EnvironmentFile=/etc/default/openhab
User=root
Group=root