[MySensors][Serial Gateway][Hassbian] Troubleshooting adding a sensor

sergio_101 · March 11, 2018, 7:26pm

Hi, all.

I have my HomeAssistant all set up, with several Sonoff switches up and running with no problems.

I finally got around to setting up a MySensors gateway and one sensor set up. It looks like I am connecting to the gateway ok:

2018-03-11 17:54:30 INFO (Thread-13) [mysensors.gateway_serial] Connected to /dev/ttyAMA0

And when I fire it up on my dev machine, the gateway starts up fine.

When i fire up my sensor (DHT) I am getting:

 __  __       ____
|  \/  |_   _/ ___|  ___ _ __  ___  ___  _ __ ___
| |\/| | | | \___ \ / _ \ `_ \/ __|/ _ \| `__/ __|
| |  | | |_| |___| |  __/ | | \__ \  _  | |  \__ \
|_|  |_|\__, |____/ \___|_| |_|___/\___/|_|  |___/
        |___/                      2.2.0

16 MCO:BGN:INIT NODE,CP=RNNNA---,VER=2.2.0
25 TSM:INIT
26 TSF:WUR:MS=0
33 TSM:INIT:TSP OK
35 TSF:SID:OK,ID=1
37 TSM:FPAR
73 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
2080 !TSM:FPAR:NO REPLY
2082 TSM:FPAR
2118 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
4126 !TSM:FPAR:NO REPLY
4128 TSM:FPAR
4164 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
6172 !TSM:FPAR:NO REPLY
6174 TSM:FPAR
6210 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
8218 !TSM:FPAR:FAIL
8219 TSM:FAIL:CNT=1
8221 TSM:FAIL:DIS
8223 TSF:TDI:TSL
18225 TSM:FAIL:RE-INIT
18227 TSM:INIT

In reading this forum, I have followed several permutations of this issue, but I would like to look at this a bit more closely.

In the process of troubleshooting, I would like to check to see if the gateway is getting any messages at all from the sensor.

I see alot of people able to monitor what’s going on on /dev/ttyAMA0.

So, after all that, my question is, how do i got about monitoring what’s going on with my gateway while my sensor is trying to present?

Thanks so much!

martinhjelmare · March 13, 2018, 9:56am

You can activate debug level logging for the mysensors component and package. This will show the messages coming in on the serial connection to the gateway in the home assistant log.

logger:
  default: info
  logs:
    homeassistant.components.mysensors: debug
    mysensors: debug

This is also mentioned here:

sergio_101 · March 13, 2018, 6:33pm

yes, This is how I have it set up, I am just trying to monitor the interactions with the gateway and the sensor. Sort of like, monitor the traffic through /dev/ttyAMA0…

It looks as if others are doing it.

Thanks!

martinhjelmare · March 13, 2018, 6:46pm

Yes, and the log will show this. If you have set the logger like that, what is the problem?

sergio_101 · March 13, 2018, 6:59pm

I am not seeing that output in my log…

martinhjelmare · March 17, 2018, 10:58am

Are you looking at the log output in the terminal after starting hass? The frontend log will not show filtered logs from the logger component.

sergio_101 · March 26, 2018, 7:21pm

initially, i was just tail -f ing the log… I would like to be able to see if there are any interactions between the serial gateway and a sensor i am trying to present. I have seen a few people posting such logs throughout the forums, so i was trying to replicate this.

martinhjelmare · April 2, 2018, 6:57pm

Sorry, I don’t know what could be wrong. I just tested this on my development instance and tail -f on the log works for me. This is after a restart of hass. You can see that as soon as the logger component is set up, the log gets output:

2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up mqtt
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain mqtt took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up http
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain http took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up system_log
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain system_log took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up websocket_api
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain websocket_api took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up api
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain api took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up recorder
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain recorder took 0.3 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up history
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setup of domain history took 0.0 seconds.
2018-04-02 20:53:38 INFO (MainThread) [homeassistant.setup] Setting up frontend
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain frontend took 0.2 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up alarm_control_panel
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up zone
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up group
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain group took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain zone took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up config
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up logbook
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up automation
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain logbook took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain config took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain alarm_control_panel took 0.1 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain automation took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up updater
2018-04-02 20:53:39 WARNING (MainThread) [homeassistant.components.updater] Running on 'dev', only analytics will be submitted
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain updater took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up mysensors
2018-04-02 20:53:39 DEBUG (Thread-18) [mysensors.persistence] Loading sensors from persistence file /home/martin/.homeassistant/mysensors6.json
2018-04-02 20:53:39 DEBUG (Thread-19) [mysensors.persistence] Saving sensors to persistence file /home/martin/.homeassistant/mysensors6.json
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain mysensors took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setting up switch
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.setup] Setup of domain switch took 0.0 seconds.
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.components.mysensors] Adding new devices: [<Entity Lamp 1 1: off>]
2018-04-02 20:53:39 DEBUG (MainThread) [homeassistant.components.mysensors] Entity update: Lamp 1 1: value_type 2, value = 0
2018-04-02 20:53:39 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 1.37s
2018-04-02 20:53:39 INFO (MainThread) [mysensors.gateway_serial] Trying to connect to /dev/ttyACM0
2018-04-02 20:53:39 INFO (MainThread) [mysensors] Connected to Serial<id=0x7fad05dde438, open=True>(port='/dev/ttyACM0', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False)
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] Receiving 0;255;3;0;9;0 MCO:BGN:INIT GW,CP=RNNGA---,VER=2.2.0
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:0 MCO:BGN:INIT GW,CP=RNNGA---,VER=2.2.0
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:4 TSM:INIT
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:6 TSF:WUR:MS=0
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14 TSM:INIT:TSP OK
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:17 TSM:INIT:GW MODE
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:20 TSM:READY:ID=0,PAR=0,DIS=0
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:23 MCO:REG:NOT NEEDED
2018-04-02 20:53:40 INFO (MainThread) [mysensors] n:0 c:255 t:3 s:14 p:Gateway startup complete.
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:28 MCO:BGN:STP
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:34 MCO:BGN:INIT OK,TSP=1
2018-04-02 20:53:40 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:73 TSF:MSG:SEND,0-0-255-255,s=255,c=3,t=20,pt=0,l=0,sg=0,ft=0,st=OK:
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12028 TSF:MSG:READ,1-1-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12035 TSF:MSG:BC
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12038 TSF:MSG:FPAR REQ,ID=1
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12041 TSF:PNG:SEND,TO=0
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12045 TSF:CKU:OK
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12047 TSF:MSG:GWL OK
2018-04-02 20:53:52 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:12837 TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14078 TSF:MSG:READ,1-1-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14085 TSF:MSG:PINGED,ID=1,HP=1
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14090 TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14103 TSF:MSG:READ,1-1-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14113 TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14120 TSF:MSG:READ,1-1-0,s=255,c=0,t=18,pt=0,l=5,sg=0:2.2.0
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14128 TSF:MSG:READ,1-1-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14143 TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=6,pt=0,l=1,sg=0,ft=0,st=OK:M
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14150 TSF:MSG:READ,1-1-0,s=255,c=3,t=11,pt=0,l=4,sg=0:Lamp
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Node update: node 1 child 255
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Not a child update for node 1
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14157 TSF:MSG:READ,1-1-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.0
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Node update: node 1 child 255
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Not a child update for node 1
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14166 TSF:MSG:READ,1-1-0,s=1,c=0,t=3,pt=0,l=0,sg=0:
2018-04-02 20:53:54 WARNING (MainThread) [mysensors.sensor] child_id 1 already exists in children of node 1, cannot add child
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14175 TSF:MSG:READ,1-1-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14183 TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14195 TSF:MSG:READ,1-1-0,s=1,c=1,t=2,pt=2,l=2,sg=0:0
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Node update: node 1 child 1
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Entity update: Lamp 1 1: value_type 2, value = 0
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14205 TSF:MSG:READ,1-1-0,s=1,c=2,t=2,pt=0,l=0,sg=0:
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14220 TSF:MSG:SEND,0-0-1-1,s=1,c=1,t=2,pt=0,l=1,sg=0,ft=0,st=OK:0
2018-04-02 20:53:54 DEBUG (MainThread) [mysensors] n:0 c:255 t:3 s:9 p:14227 TSF:MSG:READ,1-1-0,s=1,c=1,t=2,pt=2,l=2,sg=0:0
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Node update: node 1 child 1
2018-04-02 20:53:54 DEBUG (MainThread) [homeassistant.components.mysensors] Entity update: Lamp 1 1: value_type 2, value = 0
2018-04-02 20:53:59 DEBUG (Thread-22) [mysensors.persistence] Saving sensors to persistence file /home/martin/.homeassistant/mysensors6.json

sergio_101 · April 2, 2018, 7:17pm

OH! this is good… at least i can see what a good startup of the gateway looks like… I will figure out what is wrong with my tailing the log… and i will match my output to yours, and see if i can troubleshoot that way… thanks!