Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

master vs dev branches #14

Closed
mwdng opened this issue Dec 18, 2017 · 10 comments
Closed

master vs dev branches #14

mwdng opened this issue Dec 18, 2017 · 10 comments

Comments

@mwdng
Copy link

mwdng commented Dec 18, 2017

I can't really call this an issue because I am having a impossible time working from the "dev" branch and I know that it was requested to only send issues with that branch since it is being fixed and repaired as we go.

Here is an error I am getting:

2017-12-17 19:10:17 ERROR Serial: Serial read error from /dev/ttyUSB0 Traceback (most recent call last): File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/network/Serial.py", line 174, in read_from_link self.signal_read.emit(self, data) File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/Signal.py", line 50, in emit slot(*args, **kwargs) File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/Protocol.py", line 255, in _data_read self._process_msg(msg) File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/Protocol.py", line 277, in _process_msg status = self._write_handler.msg_received(self, msg) File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/handler/DeviceDbGet.py", line 104, in msg_received self.on_done(True, "Database received") File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/handler/DeviceRefresh.py", line 123, in on_done self.device.db.set_delta(msg.cmd1) AttributeError: 'str' object has no attribute 'cmd1' 2017-12-17 19:10:23 WARNING Protocol: Last message timed out

I can get more details but I would really like some help getting the "dev" branch working. I used the "quick start" guide as a starting point with the master branch a few weeks back, but no matter what I seem to do the only code that will run is the master branch. I am more than sure it's me. Any help would be greatly appreciated.

Michael

@TD22057
Copy link
Owner

TD22057 commented Dec 18, 2017

Please use the preview to check the formatting - that error is really hard to read. I think maybe you're not on the current dev branch. Note this line in the error:

File "/home/michael/insteon-mqtt/venv/lib/python3.5/site-packages/insteon_mqtt/handler/DeviceDbGet.py", line 104,
in msg_received self.on_done(True, "Database received")

But when I look at the dev branch line 104, I don't see that line at all: https://github.com/TD22057/insteon-mqtt/blob/dev/insteon_mqtt/handler/DeviceDbGet.py#L104

So my guess is that you somehow have a mix of the dev/main or caught a revision of the dev branch that wasn't working. Try updating (git pull; git checkout dev I think). I usually don't bother installing when I'm working (export PYTHONPATH=.; ./scripts/insteon-mqtt start config.yaml) so you could try that too (i.e. set up the venv but don't install insteon-mqtt into it).

@larizzo
Copy link

larizzo commented Dec 18, 2017

@mwdng You can also use:
git clone -b dev --single-branch 'https://github.com/TD22057/insteon-mqtt.git'

@mwdng
Copy link
Author

mwdng commented Dec 19, 2017

@TD22057 & @larizzo Thanx for the direction I just created a new env and did a git clone only for the dev branch. After a little work on the config file, I am at least in the right place for now we will see how it goes when it is time to pull updates again. BTW: Is there another place to post just general comments and discussions (on this project) or is everything at this point going here? @larizzo the only thing I did different was I didn't do the "--single-branch" is it required? I did get only the dev branch. Just don't something else to bit me in the but later.
thanks again
Michael

@larizzo
Copy link

larizzo commented Dec 19, 2017

@mwdng The only difference is you have the 2 other branches also but you are in the DEV branch. You can switch between branches with the instructions @TD22057 put.

@mwdng
Copy link
Author

mwdng commented Dec 21, 2017

Ok, back where I started. Below is an error that I get doing the same operation two different ways. I think that they are related but not sure. Please take a look and let me know what you think. it seems to happen with different commands but I thought I would look at them one at a time.

`command line entry:

(dev_env) michael@ubuntu-dev:~/insteon-mqtt$ insteon-mqtt refresh config.yaml 0d.77.2c

returned from above command:

Commanding Dimmer device 0d.77.2c hall_2 cmd=refresh
Dimmer 0d.77.2c refresh at level 0
Refresh complete

Results: (config.yaml log set to "10")

2017-12-19 13:14:12 INFO Mqtt: MQTT message insteon/command/0d.77.2c b'{"cmd": "refresh", "force": false, "session": "2968331454"}'
2017-12-19 13:14:12 UI Mqtt: Commanding Dimmer device 0d.77.2c hall_2 cmd=refresh
2017-12-19 13:14:12 INFO Base: Device 0d.77.2c cmd: status refresh
2017-12-19 13:14:12 INFO Protocol: Write to modem: Std: 0d.77.2c, Type.DIRECT, 19 00
2017-12-19 13:14:12 INFO Protocol: Read 0x62: Std: 0d.77.2c, Type.DIRECT, 19 00 ack: True
2017-12-19 13:14:12 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/2968331454 b'{"type": "MESSAGE", "data": "Commanding Dimmer device 0d.77.2c hall_2 cmd=refresh"}'
2017-12-19 13:14:13 INFO Protocol: Read 0x50: Std: 0d.77.2c->0f.e0.a5 Type.DIRECT_ACK cmd: 02 00
2017-12-19 13:14:13 UI Dimmer: Dimmer 0d.77.2c refresh at level 0
2017-12-19 13:14:13 INFO Dimmer: Setting device 0d.77.2c 'hall_2' on 0
2017-12-19 13:14:13 INFO Dimmer: MQTT received level change 0d.77.2c 'hall_2' = 0
2017-12-19 13:14:13 UI Mqtt: Refresh complete
2017-12-19 13:14:13 INFO DeviceRefresh: Device 0d.77.2c db out of date (got 2 vs None), refreshing
2017-12-19 13:14:13 INFO Protocol: Write to modem: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-19 13:14:13 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/2968331454 b'{"type": "MESSAGE", "data": "Dimmer 0d.77.2c refresh at level 0"}'
2017-12-19 13:14:13 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/2968331454 b'{"type": "MESSAGE", "data": "Refresh complete"}'
2017-12-19 13:14:13 INFO Protocol: Read 0x62: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00 ack: True
00 00 00 00 00 00 00 00 00 00 00 00 00 d1
2017-12-19 13:14:13 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/2968331454 b'{"type": "END", "data": null}'
2017-12-19 13:14:19 WARNING Base: Handler timed out 1 of 3 sent: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-19 13:14:19 WARNING Protocol: Last message timed out
2017-12-19 13:14:19 INFO Protocol: Write to modem: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-19 13:14:19 INFO Protocol: Read 0x62: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00 ack: True
00 00 00 00 00 00 00 00 00 00 00 00 00 d1
2017-12-19 13:14:25 WARNING Base: Handler timed out 3 of 3 sent: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-19 13:14:25 WARNING Protocol: Last message timed out
2017-12-19 13:14:25 INFO Protocol: Write to modem: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-19 13:14:25 INFO Protocol: Read 0x62: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00 ack: True
00 00 00 00 00 00 00 00 00 00 00 00 00 d1
2017-12-19 13:14:31 WARNING Base: Handler timed out - no more retries (5 sent)
2017-12-19 13:14:31 WARNING Protocol: Last message timed out

I think it is related to the same issue but it shows up a little differently:

From mqtt:
topic publish:
insteon/command/0d.77.2c
payload:
{
"cmd" : "refresh",
"force" : false
}

Note: I also tried changing the force flag to true and still got the same issue.

Results:

2017-12-19 13:21:17 INFO Mqtt: MQTT message insteon/command/0d.77.2c b'{\n"cmd" : "refresh", \n"force" : false\n}'
2017-12-19 13:21:17 UI Mqtt: Commanding Dimmer device 0d.77.2c hall_2 cmd=refresh
2017-12-19 13:21:17 INFO Base: Device 0d.77.2c cmd: status refresh
2017-12-19 13:21:17 INFO Protocol: Write to modem: Std: 0d.77.2c, Type.DIRECT, 19 00
2017-12-19 13:21:17 INFO Protocol: Read 0x62: Std: 0d.77.2c, Type.DIRECT, 19 00 ack: True
2017-12-19 13:21:18 INFO Protocol: Read 0x50: Std: 0d.77.2c->0f.e0.a5 Type.DIRECT_ACK cmd: 02 00
2017-12-19 13:21:18 UI Dimmer: Dimmer 0d.77.2c refresh at level 0
2017-12-19 13:21:18 INFO Dimmer: Setting device 0d.77.2c 'hall_2' on 0
2017-12-19 13:21:18 INFO Dimmer: MQTT received level change 0d.77.2c 'hall_2' = 0
2017-12-19 13:21:18 UI Mqtt: Refresh complete
2017-12-19 13:21:18 ERROR Serial: Serial read error from /dev/ttyUSB0
Traceback (most recent call last):
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/network/Serial.py", line 174, in read_from_link
self.signal_read.emit(self, data)
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/Signal.py", line 50, in emit
slot(*args, **kwargs)
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/Protocol.py", line 255, in _data_read
self._process_msg(msg)
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/Protocol.py", line 277, in _process_msg
status = self._write_handler.msg_received(self, msg)
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/handler/DeviceRefresh.py", line 79, in msg_received
self.callback(msg)
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/device/Dimmer.py", line 318, in handle_refresh
on_done(True, "Refresh complete", msg.cmd2)
File "/home/michael/insteon-mqtt/dev_env/lib/python3.5/site-packages/insteon_mqtt/mqtt/Mqtt.py", line 274, in on_done
end_reply()
TypeError: () missing 1 required positional argument: 'dummy'
2017-12-19 13:21:24 WARNING Base: Handler timed out - no more retries (4 sent)
2017-12-19 13:21:24 WARNING Protocol: Last message timed out
`
Also, I did think that it was the msg.cmd2 having an issue being "0" (from dimmer.py) so I did try setting the device to something other that 0. Thats me just trying. That didn't change anything either.
and if it is pilot error please let me know that too. and if this doesn't belong here the just let me know.

Michael

@TD22057
Copy link
Owner

TD22057 commented Dec 21, 2017

Something is still weird in your branch, or in the install, or how it's being run. One problem is that the output mqtt command you showed is wrong. When the cmd line tools sends a command, there is a session ID sent which allows the reply to work properly. When I use the dev branch and send a refresh command, the MQTT packet sequence is this:

insteon/command/48.b0.ad       {"session": "3251627659", "cmd": "refresh", "force": false}
insteon/command/48.b0.ad/session/3251627659 {"data": "Commanding Dimmer device 48.b0.ad  cmd=refresh", "type": "MESSAGE"}
insteon/command/48.b0.ad/session/3251627659 {"data": "Dimmer 48.b0.ad refresh at level 0", "type": "MESSAGE"}
insteon/48.b0.ad/state         { "state" : "OFF", "brightness" : 0 }
insteon/command/48.b0.ad/session/3251627659 {"data": "Refresh complete", "type": "MESSAGE"}
insteon/command/48.b0.ad/session/3251627659 {"data": null, "type": "END"}

From the first example, that looks like it works. Not sure why there is no session key in the second one - I don't see how that's possible. I pushed a change to dev to fix the exception you saw, but it should have never reached there in the first place.

As for the time out - I don't have any idea about that one. Obviously the device is available - it got the level just fine in the reply. But when it sent the command to download the db, it got no response. That command works fine for every device that I own. Do you have the model number of the device?

@mwdng
Copy link
Author

mwdng commented Dec 22, 2017

Ok, here is what I know for now. since the last adjustment the errors are more similar. So I have went through all the devices (still have more to add to insteon-mqtt later) I found issues with 2 of them, one is a keypadlinc 2486D V1.8 and one is a dimmer 2476D V3.3. they both still give me errors when I attempt to refresh them from the cmd line (insteon-mqtt refresh -f config.yaml aa.bb.cc ). I have quite a few older insteon units (no X10) mixed in from the last 10 yrs or so. Really not sure what I will find as I keep adding them.

dimmer Issue from above:
`2017-12-22 12:01:23 INFO Mqtt: MQTT message insteon/command/0d.77.2c b'{"session": "627837134", "force": false, "cmd": "refresh"}'
2017-12-22 12:01:23 UI Mqtt: Commanding Dimmer device 0d.77.2c hall_2 cmd=refresh
2017-12-22 12:01:23 INFO Base: Device 0d.77.2c cmd: status refresh
2017-12-22 12:01:23 INFO Protocol: Write to modem: Std: 0d.77.2c, Type.DIRECT, 19 00
2017-12-22 12:01:23 INFO Protocol: Read 0x62: Std: 0d.77.2c, Type.DIRECT, 19 00 ack: True
2017-12-22 12:01:23 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/627837134 b'{"data": "Commanding Dimmer device 0d.77.2c hall_2 cmd=refresh", "type": "MESSAGE"}'
2017-12-22 12:01:23 INFO Protocol: Read 0x50: Std: 0d.77.2c->0f.e0.a5 Type.DIRECT_ACK cmd: 02 00
2017-12-22 12:01:23 UI Dimmer: Dimmer 0d.77.2c refresh at level 0
2017-12-22 12:01:23 INFO Dimmer: Setting device 0d.77.2c 'hall_2' on 0
2017-12-22 12:01:23 INFO Dimmer: MQTT received level change 0d.77.2c 'hall_2' = 0
2017-12-22 12:01:23 UI Mqtt: Refresh complete
2017-12-22 12:01:23 INFO DeviceRefresh: Device 0d.77.2c db out of date (got 2 vs None), refreshing
2017-12-22 12:01:23 INFO Protocol: Write to modem: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-22 12:01:23 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/627837134 b'{"data": "Dimmer 0d.77.2c refresh at level 0", "type": "MESSAGE"}'
2017-12-22 12:01:23 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/627837134 b'{"data": "Refresh complete", "type": "MESSAGE"}'
2017-12-22 12:01:23 INFO Mqtt: MQTT message insteon/command/0d.77.2c/session/627837134 b'{"data": null, "type": "END"}'
2017-12-22 12:01:23 INFO Protocol: Read 0x62: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00 ack: True
00 00 00 00 00 00 00 00 00 00 00 00 00 d1
2017-12-22 12:01:29 WARNING Base: Handler timed out 1 of 3 sent: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-22 12:01:29 WARNING Protocol: Last message timed out
2017-12-22 12:01:29 INFO Protocol: Write to modem: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-22 12:01:29 INFO Protocol: Read 0x62: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00 ack: True
00 00 00 00 00 00 00 00 00 00 00 00 00 d1
2017-12-22 12:01:35 WARNING Base: Handler timed out 3 of 3 sent: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-22 12:01:35 WARNING Protocol: Last message timed out
2017-12-22 12:01:35 INFO Protocol: Write to modem: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017-12-22 12:01:35 INFO Protocol: Read 0x62: Ext: 0d.77.2c, Type.DIRECT ext, 2f 00 ack: True
00 00 00 00 00 00 00 00 00 00 00 00 00 d1
2017-12-22 12:01:41 WARNING Base: Handler timed out - no more retries (5 sent)
2017-12-22 12:01:41 WARNING Protocol: Last message timed out

`
Also, no matter which devices (w/issuse or w/o issues) when I try to publish a mqtt payload to the broker I get no session ID. It must be something that I am doing wrong but not sure what it is. Here is what I am sending:

insteon/command/14.37.2b
{
"cmd" : "refresh",
"force" : true
}

This is what I get back:
2017-12-22 11:23:05 INFO Mqtt: MQTT message insteon/command/14.37.2b b'{\n"cmd" : "refresh", \n"force" : true\n}' 2017-12-22 11:23:05 UI Mqtt: Commanding Dimmer device 14.37.2b table_lamp cmd=refresh 2017-12-22 11:23:05 INFO Base: Device 14.37.2b cmd: status refresh 2017-12-22 11:23:05 INFO Protocol: Write to modem: Std: 14.37.2b, Type.DIRECT, 19 00 2017-12-22 11:23:05 INFO Protocol: Read 0x62: Std: 14.37.2b, Type.DIRECT, 19 00 ack: True 2017-12-22 11:23:05 INFO Protocol: Read 0x50: Std: 14.37.2b->0f.e0.a5 Type.DIRECT_ACK cmd: 00 00 2017-12-22 11:23:05 UI Dimmer: Dimmer 14.37.2b refresh at level 0 2017-12-22 11:23:05 INFO Dimmer: Setting device 14.37.2b 'table_lamp' on 0 2017-12-22 11:23:05 INFO Dimmer: MQTT received level change 14.37.2b 'table_lamp' = 0 2017-12-22 11:23:05 UI Mqtt: Refresh complete 2017-12-22 11:23:05 INFO DeviceRefresh: Device 14.37.2b db out of date (got 0 vs 0), refreshing 2017-12-22 11:23:05 INFO Protocol: Write to modem: Ext: 14.37.2b, Type.DIRECT ext, 2f 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 2017-12-22 11:23:05 INFO Protocol: Read 0x62: Ext: 14.37.2b, Type.DIRECT ext, 2f 00 ack: True 00 00 00 00 00 00 00 00 00 00 00 00 00 d1 2017-12-22 11:23:06 INFO Protocol: Read 0x50: Std: 14.37.2b->0f.e0.a5 Type.DIRECT_ACK cmd: 2f 00 2017-12-22 11:23:06 INFO DeviceDbGet: 14.37.2b device ACK response 2017-12-22 11:23:09 INFO Protocol: Read 0x51: Ext: 14.37.2b->0f.e0.a5 Type.DIRECT ext cmd: 2f 00 01 01 0f f7 00 e2 01 0f e0 a5 ff 1c 00 d1 2017-12-22 11:23:09 UI DeviceDbGet: Entry: 0ff7: 0f.e0.a5 grp: 1 type: CTRL data: 0xff 0x1c 0x00 2017-12-22 11:23:10 INFO Protocol: Read 0x51: Ext: 14.37.2b->0f.e0.a5 Type.DIRECT ext cmd: 2f 00 01 01 0f ef 00 00 00 00 00 00 00 00 00 d1 2017-12-22 11:23:10 UI DeviceDbGet: Entry: 0fef: 00.00.00 grp: 0 type: RESP data: 0x00 0x00 0x00 (LAST) 2017-12-22 11:23:10 INFO DeviceRefresh: 14.37.2b database download complete DeviceDb: (delta None) 0ff7: 0f.e0.a5 grp: 1 type: CTRL data: 0xff 0x1c 0x00 Unused: 0fef: 00.00.00 grp: 0 type: RESP data: 0x00 0x00 0x00 (LAST) GroupMap 1 -> ['0f.e0.a5']
FYI: I am sending the mqtt commands from "MQTTBox" in windows 10. Also I am running the code w the latest updates( checked that first)

Michael

@TD22057
Copy link
Owner

TD22057 commented Dec 22, 2017

That probably explains it.

  1. the "cmd" MQTT api is designed to work with the command line tool which allows sending the commands and getting replies back for status. (scripts/insteon-mqtt). It can be used like you're using it as well, but you won't get replies back with the results.

  2. Insteon changed command protocols ~5 years ago. I know because the last developers guide is from 2007 and some of the commands no longer work. So it's probably that the older devices are still using the old commands. I may be able to help with that, but it won't happen anytime soon I'm afraid (and I don't own any of those devices obviously) - I have some other things to do to get my devices finished first (feel free to fork and try and get your devices working if you want).

@mwdng
Copy link
Author

mwdng commented Dec 22, 2017

Ok.(1) Cool at least now I know why and what to expect (2) For now it's not a problem, it's just others with older devices will have to know so they don't get bogged down chasing it. Everything still works within Home assistant where I use it (experimenting with Node Red) so its not a show stopper. As far as forking the project I am not sure that I am ready for that just yet. Not really a python developer but this would definitely be a challenge and who doesn't need a challenge. So if I head that way I might need a little help w development tools to start with. So for now I will continue testing against my setup.
ThanX
Michael

@TD22057
Copy link
Owner

TD22057 commented Dec 23, 2017

FYI it looks like device 14.37.2b did respond to the refresh command in the example above. I've added issue #17 to explicitly support older devices. If it's ok with you, I'll close this one out (feel free to keep asking questions here if you want).

@TD22057 TD22057 closed this as completed Dec 23, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants