Presentation and power up problem (1.3 Beta 2)

I did not have a capacitor on the soilmoist sensor so I added a 10uF and tried again. Still no parent node and still not reporting status like it should. I’ll hock it up to serial monitor tomorrow and see…

The result of RF24:write is not useful when autoAck functionality is tuned off (I think it always will return false). We should change RF24:write to the non blocking RF24:startWrite instead.

The TX_DS bit always returns true unless something went wrong with actually sending the msg. If “Auto ACK” is in use, it takes that one step further and requires the ACK to be RX’ed. MAX_RT will never be set unless “Auto ACK” is in use.

It was TX_DS bit that indicated that the write start delay was not being used correctly. The radio contains an 8051 micro. On power up it will probably be running a few required instructions before it can RX/TX. I suspect when the 8051 was commanded to write it was not ready. As a result it never set the TX_DS bit and a timeout was detected in the function.

The SPI interface is always running and is probably just some sort of state machine that interacts & controls the 8051. So it’s useful to watch the TX_DS - as it can indicate the 8051 CPU is not fully operational.

And also it’s probably good to block here. That would probably ensures the TX FIFO doesn’t get overrun.

It’s useful to turn on the debugging in the radio library as well.

Just another point I should mention on the power up problem:

I use one of these programming interfaces:

https://www.sparkfun.com/products/9873

When downloading a new program most of the time the power up problem did not occur. However it always occurred if I used the hardware reset button. Interestingly both methods just operate the ATmega reset line. Can only assume the timing is different because the Atmega bootstrap loader is acting differently in each case? I assume the bootstrap loader is monitoring the serial line to decide on what it should be doing.

    if (!broadcast && (radioId == GATEWAY_ADDRESS)) {
The idea is that even sensors waits for a soft-ack from receiver (this could later be used for automatic resending of important messages). Broadcast messages is the exception as we handle them differently.

Every transmission is expecting a software ACK. Probably even the transmission of the Software ACK expects a Software ACK. Something needs a bit of tweaking. At the moment, the software ACK is only ever sent by the main gateway - see sensor.cpp

if (msg.header.from == GATEWAY_ADDRESS && // If this is variable message from sensor net gateway. Send ack back. msg.header.messageType == M_SET_VARIABLE) { // Send back ack message to sensor net gateway sendVariableAck(); }

After Henrik and I conducted more extensive testing, we found that some soft ACKs would still timeout. Increasing the ACK_SEND_DELAY from 5 milliseconds to 10 milliseconds seems to resolve the issue. That change has been pushed to the github repo so feel free to grab the latest for testing.

Also, the Vera plugin was slightly updated to handle missing parent nodes more robustly.

For those of you who have missing parent nodes, you can take the following steps to create them.

[ol][li]Pull the latest Vera and Arduino git repos[/li]
[li]Flash your gateway and sensors with the latest Arduino git repo[/li]
[li]Upload the latest Vera plugin to your Vera and reload[/li]
[li]Run inclusion mode and reset each node that has a missing parent before inclusion mode ends[/li]
[li]You may have to reload the Vera dashboard to see the new parents but they all should be there[/li][/ol]

Cheers,
Bruce

Thanks A-lurker. In my testing, I have verified that the issue is resolved when resetting under the following reset scenarios on a Mini Pro 5V/16MHz.

[ul][li]Reset by upload[/li]
[li]Reset by closing/opening the serial console[/li]
[li]Reset by pressing the reset button on the Mini Pro[/li][/ul]

Let us know if these changes up to commit c5661caf17a5e917d6d0d64edc1dae359c813231 improves the message send reliability for your network.

I’ve edited this post - its previous contents were not very useful.

The first message after power up is now sent reliably but there is still some major handshaking issue. I’m using an Ethernet connected gateway and and an 8 MHz slave - so there may be some timing issue due to hardware differences.

[quote=“a-lurker, post:24, topic:180325”] if (!broadcast && (radioId == GATEWAY_ADDRESS)) {

The idea is that even sensors waits for a soft-ack from receiver (this could later be used for automatic resending of important messages). Broadcast messages is the exception as we handle them differently.

Every transmission is expecting a software ACK. Probably even the transmission of the Software ACK expects a Software ACK. Something needs a bit of tweaking. At the moment, the software ACK is only ever sent by the main gateway - see sensor.cpp

if (msg.header.from == GATEWAY_ADDRESS && // If this is variable message from sensor net gateway. Send ack back. msg.header.messageType == M_SET_VARIABLE) { // Send back ack message to sensor net gateway sendVariableAck(); }[/quote]

No thats a variable ack. It is a message that can get travel through several nodes.

The “soft-ack” is done in Sensor::readMessage() and just acks all received messages back to sender.

Sorry for the confusion.

I managed to get the parent node for the soilmoist sensor but it required like 50 restarts so I guess it was only luck.

If I removed sleep mode it works perfectly.

Here is what serial monitor look like for the sensor when it use sleep mode, lots of gibberish on the serial also. If I remove sleep mode I get no gibberish:
(also tried to re-ad the gw power up but it did not seem to help)

Tried now with a motion sensor and this one works perfectly so it seems like there is some problem with my soilmoist sensors hardware

I added the same delay I found from the motion sensor before the power down and this cleens out the giberich from the serial log but stil communication is realy bad for this sensor.

Started sensor.<\n> Relay=0, distance=1<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=0,ty=17,cr=179: 1.2+<\n> Ack: receive timeout<\n> Ack: received non ack msg.<\n> Send failed.<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=4,ty=7,cr=137: 0<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=4,ty=14,cr=239: Soil Moisture Sensor<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=4,ty=15,cr=2: 1.0<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=0,ty=1,cr=160: 1.2+<\n> Sent successfully<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Sent successfully<\n> 0<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=163: 1<\n> Sent successfully<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Ack: receive timeout<\n> Ack: received non ack msg.<\n> Send failed.<\n> 0<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=163: 1<\n> Ack: receive timeout<\n> Ack: received non ack msg.<\n> Send failed.<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Ack: receive timeout<\n> Ack: received non ack msg.<\n> Send failed.<\n> 0<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=163: 1<\n> Sent successfully<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Ack: receive timeout<\n> Ack: received non ack msg.<\n> Send failed.<\n>

GW:

0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=4,t=7,cr=137(ok): 0<\n> 1;255;4;7;0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=4,t=14,cr=239(ok): Soil Moistu<\n> 1;255;4;14;Soil Moisture Sensor<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=4,t=15,cr=2(ok): 1.0<\n> 1;255;4;15;1.0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=0,t=1,cr=160(ok): 1.2+<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;0;1;1.2+<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=196(ok): 0<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=163(ok): 1<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;1<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=163(ok): 1<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;1<\n>

I can confirm now that there is a hardware issue on my soilmoist sensor. Managed to get it working quite well now…

@korttoma
I looks like the node presentation message still doesn’t reach the gateway.

When I verified the “sleeping” motion sensor with the latest code it looked very good here. It is weird we have so different results. I’m starting to wonder if it is congestion the radio frequency your using?

What happens if you edit the Sensor.cpp setupRadio() and add:

RF24::powerUp();
delay(100);

At the end of the method. Like this:

[code]void Sensor::setupRadio(rf24_pa_dbm_e paLevel, uint8_t channel, rf24_datarate_e dataRate) {
failedTransmissions = 0;

// Start up the radio library
RF24::begin();
RF24::enableDynamicPayloads();
RF24::setAutoAck(false);
RF24::setRetries(15, 15);
RF24::setPALevel(paLevel);
RF24::setChannel(channel);
RF24::setDataRate(dataRate);
RF24::setCRCLength(RF24_CRC_16);

// All repeater nodes and gateway listen to broadcast pipe (for PING messages)
if (isRelay) {
	RF24::openReadingPipe(BROADCAST_PIPE, TO_ADDR(BROADCAST_ADDRESS));
}

RF24::powerUp();
delay(100);
}[/code]

Like I said. There was a hardware problem on the soilmoist sensor. Pin 9 was not connecting properly.

All seems fine now:

Started sensor.<\n> Relay=0, distance=1<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=0,ty=17,cr=179: 1.2+<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=4,ty=7,cr=137: 0<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=4,ty=14,cr=239: Soil Moisture Sensor<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=4,ty=15,cr=2: 1.0<\n> Sent successfully<\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=0,ty=1,cr=160: 1.2+<\n> Sent successfully<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Sent successfully<\n> 0<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=163: 1<\n> Sent successfully<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Sent successfully<\n> 0<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=163: 1<\n> Sent successfully<\n> 1<\r><\n> Relaying message back to gateway.<\n> Tx: fr=1,to=0,la=1,ne=0,ci=0,mt=1,ty=16,cr=196: 0<\n> Sent successfully<\n>

GW:

0;0;4;11;Arduino startup complete.<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=0,t=17,cr=179(ok): 1.2+<\n> 0;0;4;11;Message addressed for this node.<\n> 1;255;0;17;1.2+<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=4,t=7,cr=137(ok): 0<\n> 1;255;4;7;0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=4,t=14,cr=239(ok): Soil Moistu<\n> 1;255;4;14;Soil Moisture Sensor<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=255,mt=4,t=15,cr=2(ok): 1.0<\n> 1;255;4;15;1.0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=0,t=1,cr=160(ok): 1.2+<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;0;1;1.2+<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=196(ok): 0<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=163(ok): 1<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;1<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=196(ok): 0<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;0<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=163(ok): 1<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;1<\n> 0;0;4;11;Message available on pipe 1<\n> 0;0;4;11;Sent ack msg to 1<\n> 0;0;4;11;Rx: fr=1,to=0,la=1,ci=0,mt=1,t=16,cr=196(ok): 0<\n> 0;0;4;11;Message addressed for this node.<\n> 1;0;1;16;0<\n>

Or do you still see something I don’t?

Looks good!

Seems like I’m quite talented at producing a new problem every time I solve an old one. Thanks for your patience and support.

I have updated the new code on my Vera, Serial Gateway and Sensors.
I am getting very strange behavior now on all devices.

On one Motion sensor I had to switch it from USB power to brick power and I get the following

Started sensor.
Relay=0, distance=255
No radio id found in EEPROM fetching one from sensor net gateway
Relaying message back to gateway.
Tx: fr=255,to=0,la=255,ne=0,ci=255,mt=4,ty=5,cr=136:
Ack: receive timeout
Relaying message back to gateway.
Tx: fr=255,to=0,la=255,ne=0,ci=255,mt=4,ty=5,cr=136:
Ack: receive timeout
Relaying message back to gateway.
Tx: fr=255,to=0,la=255,ne=0,ci=255,mt=4,ty=5,cr=136:
Ack: receive timeout

On another sensor I can arm and disarm but I can never get it to sense motion. If I disconnect power from the motion sensor pin 1 and 3 all of a sudden I get “flapping” back and forth as log shows below. (and green light on Gateway flashes)
[table]
[tr]
[td]50 03/30/14 15:16:07.606 luup_log:123: Arduino: Log: Rx: fr=2,to=0,la=2,ci=0,mt=1,t=16,cr=36(ok): 1 <0x2eeaa680>
50 03/30/14 15:16:07.607 luup_log:123: Arduino: Log: Message addressed for this node. <0x2eeaa680>
50 03/30/14 15:16:07.608 luup_log:123: Arduino: Set Var: 2;0;1;16;1 <0x2eeaa680>
50 03/30/14 15:16:07.609 luup_log:123: Arduino: Setting variable ‘Tripped’ to value ‘1’ <0x2eeaa680>
50 03/30/14 15:16:07.609 luup_log:123: Arduino: urn:micasaverde-com:serviceId:SecuritySensor1,Tripped, 1, 133 <0x2eeaa680>
06 03/30/14 15:16:07.609 Device_Variable::m_szValue_set device: 133 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: Tripped was: 0 now: 1 #hooks: 1 upnp: 0 v:0xdd7428/NONE duplicate:0 <0x2eeaa680>
50 03/30/14 15:16:07.610 luup_log:123: Arduino: urn:micasaverde-com:serviceId:SecuritySensor1,LastTrip, 1396206967, 133 <0x2eeaa680>
06 03/30/14 15:16:07.611 Device_Variable::m_szValue_set device: 133 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: LastTrip was: 1396206966 now: 1396206967 #hooks: 0 upnp: 0 v:0xdd73e8/NONE duplicate:0 <0x2eeaa680>
50 03/30/14 15:16:07.612 luup_log:123: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1396206967, 134 <0x2eeaa680>
06 03/30/14 15:16:07.612 Device_Variable::m_szValue_set device: 134 service: urn:micasaverde-com:serviceId:HaDevice1 variable: LastUpdate was: 1396206967 now: 1396206967 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2eeaa680>
50 03/30/14 15:16:07.613 luup_log:123: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 15:16, 134 <0x2eeaa680>
50 03/30/14 15:16:07.814 luup_log:123: Arduino: Log: Message available on pipe 1 <0x2eeaa680>
50 03/30/14 15:16:07.824 luup_log:123: Arduino: Log: Sent ack msg to 2 <0x2eeaa680>
50 03/30/14 15:16:07.834 luup_log:123: Arduino: Log: Rx: fr=2,to=0,la=2,ci=0,mt=1,t=16,cr=67(ok): 0 <0x2eeaa680>
50 03/30/14 15:16:07.836 luup_log:123: Arduino: Log: Message addressed for this node. <0x2eeaa680>
50 03/30/14 15:16:07.837 luup_log:123: Arduino: Set Var: 2;0;1;16;0 <0x2eeaa680>
50 03/30/14 15:16:07.837 luup_log:123: Arduino: Setting variable ‘Tripped’ to value ‘0’ <0x2eeaa680>
50 03/30/14 15:16:07.837 luup_log:123: Arduino: urn:micasaverde-com:serviceId:SecuritySensor1,Tripped, 0, 133 <0x2eeaa680>
06 03/30/14 15:16:07.838 Device_Variable::m_szValue_set device: 133 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: Tripped was: 1 now: 0 #hooks: 1 upnp: 0 v:0xdd7428/NONE duplicate:0 <0x2eeaa680>
50 03/30/14 15:16:07.839 luup_log:123: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1396206967, 133 <0x2eeaa680>
06 03/30/14 15:16:07.839 Device_Variable::m_szValue_set device: 133 service: urn:micasaverde-com:serviceId:HaDevice1 variable: LastUpdate was: 1396206967 now: 1396206967 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2eeaa680>
50 03/30/14 15:16:07.840 luup_log:123: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1396206967, 134 <0x2eeaa680>
06 03/30/14 15:16:07.840 Device_Variable::m_szValue_set device: 134 service: urn:micasaverde-com:serviceId:HaDevice1 variable: LastUpdate was: 1396206967 now: 1396206967 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:1 <0x2eeaa680>
50 03/30/14 15:16:07.841 luup_log:123: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 15:16, 134 <0x2eeaa680>
50 03/30/14 15:16:08.034 luup_log:123: Arduino: Log: Message available on pipe 1 <0x2eeaa680>
50 03/30/14 15:16:08.054 luup_log:123: Arduino: Log: Sent ack msg to 2 <0x2eeaa680>
50 03/30/14 15:16:08.056 luup_log:123: Arduino: Log: Rx: fr=2,to=0,la=2,ci=0,mt=1,t=16,cr=36(ok): 1 <0x2eeaa680>
50 03/30/14 15:16:08.057 luup_log:123: Arduino: Log: Message addressed for this node. <0x2eeaa680>
50 03/30/14 15:16:08.058 luup_log:123: Arduino: Set Var: 2;0;1;16;1 <0x2eeaa680>
50 03/30/14 15:16:08.059 luup_log:123: Arduino: Setting variable ‘Tripped’ to value ‘1’ <0x2eeaa680>
50 03/30/14 15:16:08.059 luup_log:123: Arduino: urn:micasaverde-com:serviceId:SecuritySensor1,Tripped, 1, 133 <0x2eeaa680>
06 03/30/14 15:16:08.059 Device_Variable::m_szValue_set device: 133 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: Tripped was: 0 now: 1 #hooks: 1 upnp: 0 v:0xdd7428/NONE duplicate:0 <0x2eeaa680>
50 03/30/14 15:16:08.060 luup_log:123: Arduino: urn:micasaverde-com:serviceId:SecuritySensor1,LastTrip, 1396206968, 133 <0x2eeaa680>
06 03/30/14 15:16:08.060 Device_Variable::m_szValue_set device: 133 service: urn:micasaverde-com:serviceId:SecuritySensor1 variable: LastTrip was: 1396206967 now: 1396206968 #hooks: 0 upnp: 0 v:0xdd73e8/NONE duplicate:0 <0x2eeaa680>
50 03/30/14 15:16:08.061 luup_log:123: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1396206968, 134 <0x2eeaa680>[/td]

[/tr]
[/table]

Any ideas?