Insteonplm binding x10 dimmer not working

saddlebear · March 24, 2016, 1:38am

Hello,

I am able to get x10 switch working but not x10 dimmer. Below is the debug log for the insteonplm binding:

2016-03-23 19:25:37 INFO o.o.b.i.InsteonPLMActiveBinding[:595]- modem database has 1 entries!
2016-03-23 19:25:37 DEBUG o.o.b.i.InsteonPLMActiveBinding[:600]- modem db entry: 3D.97.D5
2016-03-23 19:26:11 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampsOnOff got command ON
2016-03-23 19:26:11 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command ON features: 1
2016-03-23 19:26:11 DEBUG o.o.b.i.i.d.RequestQueueManager[:96]- starting request queue thread
2016-03-23 19:26:11 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Switch(1:3:2) OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-23 19:26:11 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-23 19:26:11 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-23 19:26:11 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-23 19:26:11 INFO o.o.b.i.i.d.CommandHandler[:376]- X10OnOffCommandHandler: sent msg to switch B.2 ON
2016-03-23 19:26:11 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Switch(1:3:2) OUT:Cmd:0x63|rawX10:0xE2|X10Flag:0x80|
2016-03-23 19:26:11 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-23 19:26:11 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xE2|X10Flag:0x80|
2016-03-23 19:26:13 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for B.2 is empty!
2016-03-23 19:28:33 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampsOnOff got command OFF
2016-03-23 19:28:33 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command OFF features: 1
2016-03-23 19:28:33 INFO o.o.b.i.i.d.CommandHandler[:376]- X10OnOffCommandHandler: sent msg to switch B.2 OFF
2016-03-23 19:28:33 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-23 19:28:33 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Switch(1:3:2) OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-23 19:28:33 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-23 19:28:33 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-23 19:28:35 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-23 19:28:35 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Switch(1:3:2) OUT:Cmd:0x63|rawX10:0xE3|X10Flag:0x80|
2016-03-23 19:28:35 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-23 19:28:35 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xE3|X10Flag:0x80|
2016-03-23 19:28:37 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for B.2 is empty!
2016-03-23 19:28:49 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampDimmer got command 42
2016-03-23 19:28:49 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command 42 features: 1
2016-03-23 19:28:50 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampDimmer got command 42
2016-03-23 19:28:50 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command 42 features: 1

The “command 42” to dim the lamp never seems to trigger the X10 command handler; whereas, the ON and OFF commands seem to work.

Here are my item definitions:

Dimmer ChrisFloorLampDimmer “Chris Floor Lamps” (ChrisRoom) {insteonplm=“B.2:X00.00.02#dimmer”}

Switch ChrisFloorLampsOnOff “Chris Floor Lamps Switch” (ChrisRoom) {insteonplm=“B.2:X00.00.01#switch”}

Any help would be appreciated

Bernd_Pfrommer · March 24, 2016, 4:19pm

Same X10 address: B.2. Is that what you wanted?
If it’s the same device, you don’t need to install dimmer and switch separately. Just install a single dimmer item, it supports a “Switch” command as well.

saddlebear · March 24, 2016, 4:42pm

Bernd,

It was just what I had configured while I was trying to figure out the cause of the problem.

It works with the switch configuration but not the dimmer config.

Typically (and initially) I did not have the switch and the dimmer configured to the same X10 address (B.2).

Chris

Bernd_Pfrommer · March 24, 2016, 7:11pm

Can you try just a single dimmer?

saddlebear · March 25, 2016, 5:32pm

Bernd,

That helped. Having only the dimmer defined causes the X10 command handler to issue commands to the X10 modules.

However, it’s only turning the dimmer module on or off. It’s not DIMMING or brightening the lights.

It doesn’t seem to matter what level it’s set to (level 43 and 18 were shown in the log, I also tried level 1) the dimming function does not seem to be working.

So the dimming function is acting just as an “on” command.

I tested the dimming function of my lamp modules using an X10 remote via an X10 transceiver module and the dimming function does work.

I’ve included links to the X10 remote and X10 transceiver at the bottom of this email so you know which units I’m testing the dimming function with.

Here’s my default.items:

Group ChrisRoom “Chris Room” (Basement)
Group HVACRoom “HVAC Room” (Basement)

Dimmer ChrisFloorLampDimmer “Chris Floor Lamps” (ChrisRoom) {insteonplm=“B.2:X00.00.02#dimmer”}

Here’s the log:

2016-03-25 10:57:11 DEBUG o.o.b.i.i.d.ModemDBBuilder[:144]- MDB ---------------- end of modem link records -----------
2016-03-25 10:57:11 INFO o.o.b.i.InsteonPLMActiveBinding[:595]- modem database has 1 entries!
2016-03-25 10:57:11 DEBUG o.o.b.i.InsteonPLMActiveBinding[:600]- modem db entry: 3D.97.D5
2016-03-25 10:57:47 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampDimmer got command 43
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command 43 features: 2
2016-03-25 10:57:47 DEBUG o.o.b.i.i.d.RequestQueueManager[:96]- starting request queue thread
2016-03-25 10:57:47 DEBUG o.o.b.i.i.d.CommandHandler[:400]- X10PercentCommandHandler: changing level of B.2 to 43
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:57:47 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xBA|X10Flag:0x80|
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:57:47 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampDimmer got command 43
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command 43 features: 2
2016-03-25 10:57:47 DEBUG o.o.b.i.i.d.CommandHandler[:400]- X10PercentCommandHandler: changing level of B.2 to 43
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xBA|X10Flag:0x80|
2016-03-25 10:57:47 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:57:47 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xBA|X10Flag:0x80|
2016-03-25 10:57:48 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:57:48 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xBA|X10Flag:0x80|
2016-03-25 10:57:49 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for B.2 is empty!
2016-03-25 10:58:25 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampDimmer got command 18
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command 18 features: 2
2016-03-25 10:58:25 DEBUG o.o.b.i.i.d.CommandHandler[:400]- X10PercentCommandHandler: changing level of B.2 to 18
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:58:25 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xAA|X10Flag:0x80|
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:58:25 INFO o.o.b.i.InsteonPLMActiveBinding[:125]- Item: ChrisFloorLampDimmer got command 18
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:168]- processing command 18 features: 2
2016-03-25 10:58:25 DEBUG o.o.b.i.i.d.CommandHandler[:400]- X10PercentCommandHandler: changing level of B.2 to 18
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:374]- gave up waiting for query reply from device B.2
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:379]- qe taken off direct: X10Dimmer(1:3:4) OUT:Cmd:0x63|rawX10:0xAA|X10Flag:0x80|
2016-03-25 10:58:25 DEBUG o.o.b.i.i.device.InsteonDevice[:399]- next request queue processed in 2000 msec, quiettime = 2000
2016-03-25 10:58:25 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xAA|X10Flag:0x80|
2016-03-25 10:58:26 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|
2016-03-25 10:58:26 DEBUG o.o.b.i.internal.driver.Port[:382]- writing (500): OUT:Cmd:0x63|rawX10:0xAA|X10Flag:0x80|
2016-03-25 10:58:27 DEBUG o.o.b.i.i.d.RequestQueueManager[:132]- device queue for B.2 is empty!

Thanks,

Chris

X10 remote

X10 transceiver

Bernd_Pfrommer · March 25, 2016, 7:05pm

Chris,

These are the bytes that go out from the modem.

OUT:Cmd:0x63|rawX10:0xEE|X10Flag:0x00|

This translates into B2 for the address and the last byte indicating it’s a unit code (0x00), i.e. an address. So far so good.

Next command is this:

Cmd:0x63|rawX10:0xBA|X10Flag:0x80|

the trailing 0x80 says it’s a command (that’s what we want), so the “A” of 0xBA is to be interpreted as an X10 command. The command is 0xA = “Preset Dim”. So it should go to some preset dim value. It should be sending 0x4 (Dim) or 0x5(bright) instead of 0xA.

Although this actually makes sense: you are trying to set a fixed dim level, which is not possible with X10: you can only dim up or down. If you are using the classical GUI, I think you can elicit a “BRIGHTEN” command (or whatever it’s called) by long-pressing the up/down dim buttons. That may just do the trick and cause openhab to generate a brighten command, which the binding may forward (too long ago that I wrote this code, and I don’t own X10).

saddlebear · March 25, 2016, 7:53pm

Bernd,

I did some reading and apparently what needs to happen is you repeatedly send commands 1/2 second apart to achieve the given level of brightness or dimness.

There are 22 levels of brightness so to get to 50% brightness you would either turn the light on and dim it 11 levels (send 11 commands) or turn the light off and brighten it 11 levels.

Here’s a link to some code on how to bright/dim using the Insteon PLM.

http://www.madreporite.com/insteon/x10.html

It seems to be fairly simple VB code.

I’m willing to test any updates you have here since I have the X10 installation. However, I’m not a Java developer (C# and Python).

Chris

Bernd_Pfrommer · March 26, 2016, 9:25am

Chris, can you first find out how to send the Brighten/Dim commands from openhab, to see that the binding sends out the right commands in that case? Once that works you can think of ways how to generate openhab bright/dim commands to achieve what you want. I would be loathe to implement that at the binding level. This would be a hack that belongs into the upper layers.

saddlebear · March 26, 2016, 2:51pm

Bernd,

I understand your hesitation to modify this code. However, I think OpenHab has a lot of potential and there are still quite a few X10 installations out there.

I think OpenHab would work well to help people migrate from X10 to Z-Wave or ZigBee.

I believe I can modify this code to do what’s needed. I’m not a Java programmer but it’s close enough to C# that I can muddle through.

My question is: how do I obtain the current level of brightness that OpenHab thinks the X10 Lamp module is currently set to? In other words the current device state in OpenHab: On/Off or percent.

In order to adjust the brightness I need to send a sequence of bright/dim commands that’s the normalized numeric difference between the current state stored in OpenHab and the desired state.

So if the current state is 25% and the desired state is 75% I would need to send eleven X10 “bright” commands that are 1/2 second apart.

Then I can write a loop in the procedure below to repeatedly send bright/dim commands to achieve the desired state in the X10 Lamp module.

public static class X10PercentCommandHandler extends CommandHandler {

    X10PercentCommandHandler(DeviceFeature f) {

        super(f);

    }

    @Override

    public void handleCommand(InsteonPLMBindingConfig conf, Command cmd, InsteonDevice dev) {

        try {

            //

            // I did not have hardware that would respond to the PRESET_DIM codes.

            // This code path needs testing.

            //

            byte houseCode = dev.getX10HouseCode();

            byte houseUnitCode = (byte) (houseCode << 4 | dev.getX10UnitCode());

            Msg munit = dev.makeX10Message(houseUnitCode, (byte) 0x00); // send unit code

            dev.enqueueMessage(munit, m_feature);

            PercentType pc = (PercentType) cmd;

            logger.debug("{}: changing level of {} to {}", nm(), dev.getAddress(), pc.intValue());

            int level = (pc.intValue() * 32) / 100;

            byte cmdCode = (level >= 16) ? X10.Command.PRESET_DIM_2.code() : X10.Command.PRESET_DIM_1.code();

            level = level % 16;

            if (level <= 0) {

                level = 0;

            }

            houseCode = (byte) s_X10CodeForLevel[level];

            cmdCode |= (houseCode << 4);

            Msg mcmd = dev.makeX10Message(cmdCode, (byte) 0x80); // send command code

            dev.enqueueMessage(mcmd, m_feature);

        } catch (IOException e) {

            logger.error("{}: command send i/o error: ", nm(), e);

        } catch (FieldException e) {

            logger.error("{}: command send message creation error ", nm(), e);

        }

    }




    static private final int[] s_X10CodeForLevel = { 0, 8, 4, 12, 2, 10, 6, 14, 1, 9, 5, 13, 3, 11, 7, 15 };

}

saddlebear · March 26, 2016, 3:28pm

Bernd,

I just realized to make those changes I would have to set up an entire Java development environment. Unfortunately I don’t have time to do that.

I will just make do with what’s available.

Thanks for your help.

Chris

Bernd_Pfrommer · March 27, 2016, 6:09pm

I have a number of strong reasons why this logic should not go into the binding.

You cannot send out the dim messages back-to-back. You should at least put a gap of maybe 1s between each message. This means you would have to hang on to a thread (using “sleep” or the like) for something on the order of 10 seconds, which will screw up the other timeouts that the binding relies on (and has to, due to the nature of the insteon protocols). Alternatively you could implement a state machine that slowly transitions the assumed brightness level to the target level. How and where to keep the brightness state is another story.
Items state does not equal device state. You could create two dimmers in openhab that bind to the same device. Which one of the items then determines the dimming level of the device? Any logic you come up with is going to be at some level confusing to the user. That’s why the binding tries to diligently avoid keeping state, and in particular item state. This is in line with the openhab philosophy: https://github.com/openhab/openhab/wiki/How-To-Implement-A-Binding

I have two suggestions:

Implement the logic you want as a “rule”. I avoid xtend and use the jsr engine, which allows me to code in python.
See if you can live with one preset, dimmed state (like half on), and try to trigger that from within openhab. I don’t think this has been tried yet.

saddlebear · March 27, 2016, 9:16pm

Bernd,

Very good, thank you!

I will work on the rules using Python.

Chris