Problem with ID_REQUEST

Sparkman

@Tang Which controller are you using? I've added new nodes under 1.5 and it worked fine for me with the controller I have (HomeSeer).

Cheers
Al

Tang

@Sparkman I'm using agocontrol. I'm developping mysensors module.
The problem is my controller seems to have the good behaviour but the gateway does nothing.
Like Hek said it's like the frame is lost during serial transfer, but I have doubt about it.
A downgrade of my gateway to 1.4.2 version fixes the problem. My controller sends exactly the same frame (SENDING: 255;255;3;0;4;2)

015-Aug-19 11:22:48.806905 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 255-255-0 s=255,c=3,t=3,pt=0,l=0:
2015-Aug-19 11:22:48.808057 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:48.808084 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:48.808113 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 255/255;INTERNAL;0;I_ID_REQUEST;
2015-Aug-19 11:22:48.808276 [DEBUG] Free id found: 2
2015-Aug-19 11:22:48.808354 [DEBUG]  => SENDING: 255;255;3;0;4;2
2015-Aug-19 11:22:48.853276 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:48.853309 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:48.853338 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;send: 0-0-255-255 s=255,c=3,t=4,pt=0,l=1,st=fail:2
2015-Aug-19 11:22:48.857694 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:48.857715 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:48.857745 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=255,c=0,t=17,pt=0,l=5:1.4.2
2015-Aug-19 11:22:48.859906 [TRACE] Use protocol version found in current message
2015-Aug-19 11:22:48.859925 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:48.859952 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 2/255;PRESENTATION;0;S_ARDUINO_NODE;1.4.2
2015-Aug-19 11:22:48.859976 [WARNING] PRESENTATION subtype '17' not supported (protocol v1.4)
2015-Aug-19 11:22:48.864316 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:48.864316 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:48.864336 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:48.864363 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=255,c=3,t=6,pt=1,l=1:0
2015-Aug-19 11:22:48.864452 [TRACE] protocol found: 
2015-Aug-19 11:22:48.864480 [DEBUG]  => 09:22:48 2015/08/19 RECEIVING: 2/255;INTERNAL;0;I_CONFIG;0
2015-Aug-19 11:22:48.864499 [WARNING] Error: no protocol version found for this message, drop it
2015-Aug-19 11:22:50.814719 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:50.814794 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:50.814827 [DEBUG]  => 09:22:50 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=255,c=0,t=17,pt=0,l=5:1.4.2
2015-Aug-19 11:22:50.816996 [TRACE] Use protocol version found in current message
2015-Aug-19 11:22:50.817017 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:50.817044 [DEBUG]  => 09:22:50 2015/08/19 RECEIVING: 2/255;PRESENTATION;0;S_ARDUINO_NODE;1.4.2
2015-Aug-19 11:22:50.817067 [WARNING] PRESENTATION subtype '17' not supported (protocol v1.4)
2015-Aug-19 11:22:50.821411 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:50.821432 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:50.821460 [DEBUG]  => 09:22:50 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=255,c=3,t=6,pt=1,l=1:0
2015-Aug-19 11:22:50.822611 [TRACE] protocol found: 
2015-Aug-19 11:22:50.822640 [DEBUG]  => 09:22:50 2015/08/19 RECEIVING: 2/255;INTERNAL;0;I_CONFIG;0
2015-Aug-19 11:22:50.822660 [WARNING] Error: no protocol version found for this message, drop it
2015-Aug-19 11:22:52.827945 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:52.828028 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:52.828060 [DEBUG]  => 09:22:52 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=255,c=3,t=11,pt=0,l=18:Temperature Sensor
2015-Aug-19 11:22:52.830376 [TRACE] protocol found: 
2015-Aug-19 11:22:52.830412 [DEBUG]  => 09:22:52 2015/08/19 RECEIVING: 2/255;INTERNAL;0;I_SKETCH_NAME;Temperature Sensor
2015-Aug-19 11:22:52.830433 [WARNING] Error: no protocol version found for this message, drop it
2015-Aug-19 11:22:52.834780 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:52.834802 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:52.834830 [DEBUG]  => 09:22:52 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=255,c=3,t=12,pt=0,l=3:1.0
2015-Aug-19 11:22:52.837054 [TRACE] protocol found: 
2015-Aug-19 11:22:52.837086 [DEBUG]  => 09:22:52 2015/08/19 RECEIVING: 2/255;INTERNAL;0;I_SKETCH_VERSION;1.0
2015-Aug-19 11:22:52.837115 [WARNING] Error: no protocol version found for this message, drop it
2015-Aug-19 11:22:52.840755 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:52.840783 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:52.840811 [DEBUG]  => 09:22:52 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=0,c=0,t=6,pt=0,l=0:
2015-Aug-19 11:22:52.841915 [TRACE] protocol found: 
2015-Aug-19 11:22:52.841945 [DEBUG]  => 09:22:52 2015/08/19 RECEIVING: 2/0;PRESENTATION;0;S_TEMP;
2015-Aug-19 11:22:52.841965 [WARNING] Error: no protocol version found for this message, drop it
2015-Aug-19 11:22:53.729763 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:22:53.729837 [TRACE] protocol found: 1.4.2
2015-Aug-19 11:22:53.729869 [DEBUG]  => 09:22:53 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 2-2-0 s=0,c=1,t=0,pt=7,l=5:26.9
2015-Aug-19 11:22:53.731027 [TRACE] protocol found: 
2015-Aug-19 11:22:53.731058 [DEBUG]  => 09:22:53 2015/08/19 RECEIVING: 2/0;SET;0;V_TEMP;26.9

While I have it on 1.5

2015-Aug-19 11:17:24.437051 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:17:24.437124 [TRACE] protocol found: 1.5
2015-Aug-19 11:17:24.437157 [DEBUG]  => 09:17:24 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 255-255-0 s=255,c=3,t=3,pt=0,l=0,sg=0:
2015-Aug-19 11:17:24.437250 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:17:24.437269 [TRACE] protocol found: 1.5
2015-Aug-19 11:17:24.437298 [DEBUG]  => 09:17:24 2015/08/19 RECEIVING: 255/255;INTERNAL;0;I_ID_REQUEST;
2015-Aug-19 11:17:24.437464 [DEBUG] Free id found: 2
2015-Aug-19 11:17:24.437540 [DEBUG]  => SENDING: 255;255;3;0;4;2
2015-Aug-19 11:17:26.448202 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:17:26.448284 [TRACE] protocol found: 1.5
2015-Aug-19 11:17:26.448316 [DEBUG]  => 09:17:26 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 255-255-0 s=255,c=3,t=3,pt=0,l=0,sg=0:
2015-Aug-19 11:17:26.449473 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:17:26.449494 [TRACE] protocol found: 1.5
2015-Aug-19 11:17:26.449524 [DEBUG]  => 09:17:26 2015/08/19 RECEIVING: 255/255;INTERNAL;0;I_ID_REQUEST;
2015-Aug-19 11:17:26.449689 [DEBUG] Free id found: 2
2015-Aug-19 11:17:26.449765 [DEBUG]  => SENDING: 255;255;3;0;4;2
2015-Aug-19 11:17:28.455924 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:17:28.456006 [TRACE] protocol found: 1.5
2015-Aug-19 11:17:28.456039 [DEBUG]  => 09:17:28 2015/08/19 RECEIVING: 0/0;INTERNAL;0;I_LOG_MESSAGE;read: 255-255-0 s=255,c=3,t=3,pt=0,l=0,sg=0:
2015-Aug-19 11:17:28.457196 [TRACE] Use protocol version of gateway (gateway or broadcast message)
2015-Aug-19 11:17:28.457217 [TRACE] protocol found: 1.5
2015-Aug-19 11:17:28.457245 [DEBUG]  => 09:17:28 2015/08/19 RECEIVING: 255/255;INTERNAL;0;I_ID_REQUEST;
2015-Aug-19 11:17:28.457409 [DEBUG] Free id found: 2
2015-Aug-19 11:17:28.457485 [DEBUG]  => SENDING: 255;255;3;0;4;2

As you can see on sample above, on 1.4.2 the id is requested only once ("Free id found...")and all other mysensors stuff is normal while on 1.5 the sensor always requesting an id.
The code is quite the same between 1.4.X and 1.5 protocol handling and there is absolutely no difference between ID_REQUEST on 1.4.X and 1.5. Both of functions are using the same code to send data to gateway.

In view of those outputs, I don't know how to investigate more on my controller side... but good to know it works on other controller ;)
Maybe somebody has a manual procedure using an external tool and tell me how to test it :p

hek

Weird, sure that id-response adds a newline?

Does it work if you just hook up your gateway to the Arduino IDE Serial Monitor? And reply to the id-request over there (remember to turn on newline/carriage return).

Tang

I tryed with arduino IDE with "Both NL & CR" activated and the sensors received a new ID.

Here is full output of gateway:

0;0;3;0;9;read: 255-255-0 s=255,c=3,t=3,pt=0,l=0:
255;255;3;0;3;
0;0;3;0;9;send: 0-0-255-255 s=255,c=3,t=4,pt=0,l=1,st=fail:2
0;0;3;0;9;read: 2-2-0 s=255,c=0,t=17,pt=0,l=3:1.5
2;255;0;0;17;1.5
0;0;3;0;9;read: 2-2-0 s=255,c=3,t=6,pt=1,l=1:0
2;255;3;0;6;0
0;0;3;0;9;read: 2-2-0 s=255,c=0,t=17,pt=0,l=3:1.5
2;255;0;0;17;1.5
0;0;3;0;9;read: 2-2-0 s=255,c=3,t=6,pt=1,l=1:0
2;255;3;0;6;0
0;0;3;0;9;read: 2-2-0 s=255,c=3,t=11,pt=0,l=18:Temperature Sensor
2;255;3;0;11;Temperature Sensor
0;0;3;0;9;read: 2-2-0 s=255,c=3,t=12,pt=0,l=3:1.1
2;255;3;0;12;1.1
0;0;3;0;9;read: 2-2-0 s=0,c=0,t=6,pt=0,l=0:
2;0;0;0;6;
0;0;3;0;9;read: 2-2-0 s=0,c=1,t=0,pt=7,l=5:26.2
2;0;1;0;0;26.2

I will try tomorrow to update my controller sending \n\r at end of command.
Until now it seems my controller doesn't send it. Is it something new in 1.5 protocol to handle \n\r as end of command or it is a lack of my controller since the beginning?

hek

I cannot recall changing anything about how this is handled between 1.4->1.5.

Tang

Adding NL+CR to sent command fixed my problem.
Weird everything worked before 1.5. Anyway no problem now :D

Thank you for your help guys ;-)

bjacobse

@Tang Does this means that you will update some code in Agocontrol?
I also uses Agocontrol and have upgraded mysensors to ver 1.5, and I'm not able to add new sensors

Tang

@bjacobse yes i'm working on it
I just need to fix some stuff on actuator and it should be good

bjacobse

@Tang Perfect,
Let me know if I can do some testing/verification for you

Tang

@bjacobse said:

@Tang Perfect,
Let me know if I can do some testing/verification for you

I commited my stuff. You can make a try and tell me all bugs you found ;-)
Please use irc now. Thx

bjacobse

Thank you Tang, works perfekt now

Problem with ID_REQUEST

16

11.7k

11.2k

113.1k