Presentation and power up problem (1.3 Beta 2)

I recently also started from scratch. Even uninstalled the plugin and used ssh to delete all arduino related files from my Vera. Now I’m up and running again. Everything is running smoothly.
The only thing that somehow went wrong is that I did not get the “parent” devices for my sensors now when I started from scratch. They just were not created for some reason. I did not bother me before but now I see some new useful features (time of last update) planed for them so I will want them back at some point. Any one have any ideas?

[quote=“korttoma, post:1, topic:180325”]I recently also started from scratch. Even uninstalled the plugin and used ssh to delete all arduino related files from my Vera. Now I’m up and running again. Everything is running smoothly.
The only thing that somehow went wrong is that I did not get the “parent” devices for my sensors now when I started from scratch. They just were not created for some reason. I did not bother me before but now I see some new useful features (time of last update) planed for them so I will want them back at some point. Any one have any ideas?[/quote]

Just start inclusion mode and restart the sensor with missing “parent”.

attached a logfile from such a sequence. Sensors seem to report in just fine but no “new” devices are found and no parent devices are created. Seems to me like the parent devices somehow already are in Vera but can not be seen.

@hek - I’m not sure if the code below works as intended.

I have a slave device that time outs, in the code below in sensor.cpp, when sending a value back to the main gateway. Now the ACK referred to, I think is the high level ACK msg sent by sendVariableAck() - as opposed the ACK found in the inbuilt protocol of the actual hardware. The high level ACK only appears to be ever sent when the main gateway sends a message directly to an addressed slave.

So for any other case where the ACK is not sent, this code will timeout. And in fact if RF24::available() is true from a previously rx’ed msg then the code would also react to that - I’m unsure when the RF24::available() is set to false.

I wondering if this was meant assuming RF24::available() is doing what it should.

if (!broadcast && (radioId == GATEWAY_ADDRESS)) {

Also I’m getting timeouts in RF24::write in the same code below but the returned failed status is not used, when it could be useful.

Am I barking the up the wrong tree with this?? It’s a bit tricky trying to decipher all this stuff.

[code] bool ok = true;
bool broadcast = message.header.messageType == M_INTERNAL && message.header.type == I_PING;
// int retry = WRITE_RETRY;
RF24::stopListening();
RF24::openWritingPipe(TO_ADDR(dest));
RF24::write(&message, min(MAX_MESSAGE_LENGTH, sizeof(message.header) + length), broadcast);
RF24::startListening();
RF24::closeReadingPipe(WRITE_PIPE); // Stop listening to write-pipe after transmit

if (!broadcast) {
	// ---------------- WAIT FOR ACK ------------------
	 unsigned long startedWaiting = millis();
	 bool timeout = false;
	 // Wait max 100 ms
	 while ( !RF24::available() && !timeout ) {
		if (millis() - startedWaiting > 100 ) {
			timeout = true;
			debug(PSTR("Transmit: timeout\n"));
			ok = false;
		}
	 }
	// Check payload size and content
	if ( !timeout && RF24::getDynamicPayloadSize()==sizeof(uint8_t)) {
		uint8_t idest;
		RF24::read( &idest, sizeof(uint8_t));
		if (dest != idest) {
			debug(PSTR("Transmit: size problem\n"));
			ok = false;
		}
	} else {
		debug(PSTR("Transmit: general fail\n"));
		ok = false;
	}
	//--------------------
}

if (ok) {
	debug(PSTR("Sent successfully\n"));
} else {
	debug(PSTR("Send failed.\n"));
}
return ok;

}[/code]

@hek Further to timeouts above. I have found that the very first message sent after a reset of my slave device is not always sent. The slave times out and there is no reaction to the message in the plugin. So the following shows it working. When it doesn’t work the first line (Presentation) is missing:

50 03/21/14 16:38:02.864 luup_log:91: Arduino: Presentation: 1;255;0;17;1.2+ <0x30ef0680> 50 03/21/14 16:38:02.864 luup_log:91: Arduino: urn:upnp-arduino-cc:serviceId:arduinonode1,ArduinoLibVersion, 1.2+, 92 <0x30ef0680> 50 03/21/14 16:38:02.873 luup_log:91: Arduino: urn:upnp-arduino-cc:serviceId:arduinonode1,RelayNode, 0, 92 <0x30ef0680> 50 03/21/14 16:38:02.874 luup_log:91: Arduino: urn:upnp-arduino-cc:serviceId:arduinonode1,RelayNodeHR, GW, 92 <0x30ef0680> 50 03/21/14 16:38:02.887 luup_log:91: Arduino: urn:upnp-arduino-cc:serviceId:arduinonode1,SketchName, Temp: Batt, BOD off, 92 <0x30ef0680> 50 03/21/14 16:38:02.896 luup_log:91: Arduino: urn:upnp-arduino-cc:serviceId:arduinonode1,SketchVersion, 0.51, 92 <0x30ef0680> 50 03/21/14 16:38:02.909 luup_log:91: Arduino: Presentation: 1;0;0;6;1.2+ <0x30ef0680> 50 03/21/14 16:38:02.919 luup_log:91: Arduino: Sending: 1;255;4;13;M <0x30ef0680>

I turned on the debug in the RF24 lib and added more debug to RF24::write():

[code]IF_SERIAL_DEBUG(Serial.println(timeout));

bool notTimeOut = false;

// Monitor the send
do
{
status = read_register(OBSERVE_TX,&observe_tx,1);
IF_SERIAL_DEBUG(Serial.print(observe_tx,HEX));

notTimeOut = (micros() - sent_at) < timeout;

}
while( ! ( status & ( _BV(TX_DS) | _BV(MAX_RT) ) ) && (notTimeOut) );

IF_SERIAL_DEBUG(Serial.print(notTimeOut?“”:“…TIMED OUT.”));[/code]

Started sensor. Relay=0, distance=1 Radio id stored in EEPROM was: 1 Relaying message back to gateway. Tx: fr=1,to=0,la=1,ne=0,ci=255,mt=0,ty=17,cr=179: 1.2+ 60000 000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000 ...TIMED OUT ....Failed Sent successfully

When it works that string of zeroes just shows “000000”. All a bit odd but not good.

Note that I have set the bit rate to 250K - so that may be a factor.

This would explain the missing presentation message from sensors some people have reported. I wonder why/if the radio is not initialized correctly at the first send…

[quote=“petewill, post:121, topic:179310”]Tomas,

I just had the same thing happen to me. I reused a Pro Mini with a totally different sketch. I got the device I was looking for but no parent node. Also, I used a totally new ID (20) and still didn’t get the parent node. Hope that won’t be a problem in the future.

On a somewhat separate note, I had never really looked in the settings of the parent nodes. What are the “Fetch” and “Clear” buttons used for? Do I use fetch if I add another sensor, for example a light sensor to an already existing motion sensor?

Thanks,

Pete[/quote]

Glad I’m not alone with the no parent node problem. I just did a complete update of my system. Deleted everything and started from scratch. Still I get no parent nodes, all nodes include without problems but no parent nodes are found.

I have the same problem with 2 nanos not showing the parent. But everything works so I have left it alone. I have tried clearing EPROM and starting over short of starting over with gw. Since things have worked I haven’t been concerned with it and truly don’t understand the purpose of the parent node

Presentation and power up problem:

It turns out that the very first write to the radio does not implement the required power up delay. The problem is actually alluded to in the Dallas Temperature sketch and some others:

gw.powerUp(); // Powerup introduces a small delay (which is missing in radio.write powerup)

When the Radio is reset the CONFIG register has the PWR_UP bit set to 0. To power up you must set the PWR_UP bit high then delay 150 uS. This is currently not done when the first message is sent - that is the presentation message. Depending on timing it may sometimes work.

After the first write the radio is returned to being a receiver with startListening(). That also powers up the radio but crucially it also implements the required delay. So next time a message is sent, the radio is powered up and ready to go and it works.

The radio should just power up, when it’s needed, so the sketch writer doesn’t have to think about it. All the powerUp()s in the sketches could be removed.

Suggest the following mods to RF24.cpp. The idea is that any time a power up is called for - the PWR_UP bit is checked if. If it is already set, do nothing. If it is not set, set it and implement the required power up delay.

Changes: Change powerUp(). Modify startWrite() and startListening() to call powerUp() instead of manipulating the bit directly. Make sure to remove the delay found in startListening().

[code]
void RF24::powerUp(void)
{
// COMMENTED OUT
//write_register(CONFIG,read_register(CONFIG) | _BV(PWR_UP));
//delayMicroseconds(150);

// ALL THIS REPLACES THE ABOVE
uint8_t cfg = read_register(CONFIG);

// if not powered up then hit the on switch and wait while the radio starts up
if (!(cfg & _BV(PWR_UP)))
{
write_register(CONFIG,read_register(CONFIG) | _BV(PWR_UP));
delayMicroseconds(150);
}
}[/code]

[code]void RF24::startWrite( const void* buf, uint8_t len, const bool multicast )
{
// COMMENTED OUT
//write_register(CONFIG, ( read_register(CONFIG) | _BV(PWR_UP) ) & ~_BV(PRIM_RX) );

// ADDED IN
// receiver off, transmitter on
write_register(CONFIG, read_register(CONFIG) & ~_BV(PRIM_RX));

// ADDED IN
// if not powered up already, power up the radio
powerUp();

// Send the payload - Unicast (W_TX_PAYLOAD) or multicast (W_TX_PAYLOAD_NO_ACK)
write_payload( buf, len,
multicast?static_cast<uint8_t>(W_TX_PAYLOAD_NO_ACK):static_cast<uint8_t>(W_TX_PAYLOAD) ) ;

// Allons!
ce(HIGH);
delayMicroseconds(10);
ce(LOW);
}[/code]

[code]void RF24::startListening(void)
{
// COMMENTED OUT
//write_register(CONFIG, read_register(CONFIG) | _BV(PWR_UP) | _BV(PRIM_RX));

// ADDED IN
// receiver on, transmitter off
write_register(CONFIG, read_register(CONFIG) | _BV(PRIM_RX));

// ADDED IN
// if not powered up already, power up the radio
powerUp();

//write_register(CONFIG, read_register(CONFIG) | _BV(PWR_UP) | _BV(PRIM_RX));
write_register(STATUS, _BV(RX_DR) | _BV(TX_DS) | _BV(MAX_RT) );

// Restore the pipe0 adddress, if exists
if (pipe0_reading_address)
write_register(RX_ADDR_P0, reinterpret_cast<const uint8_t*>(&pipe0_reading_address), 5);

#if 0
// Flush buffers
flush_rx();
flush_tx();
#endif

// Go!
ce(HIGH);

// COMMENTED OUT
// wait for the radio to come up (130us actually only needed)
//delayMicroseconds(130);
}[/code]

[quote=“a-lurker, post:9, topic:180325”]It turns out that the very first write to the radio does not implement the required power up delay. The problem is actually alluded to in the Dallas Temperature sketch and some others:

gw.powerUp(); // Powerup introduces a small delay (which is missing in radio.write powerup)

A-lurker,

Henrik and I were IM’ing about this problem recently and felt that it was some sort of race-condition versus radio readiness but neither of us had a chance to dig into it so nice find if this is the root cause and resolves the problem. The RF24 library is a 3rd party library and I am sure the author would welcome your bug fixes/improvements. It is available on GitHub so if you are a GitHub user, you could fork it, patch it, and offer the updates via a pull-request. If you aren’t a GitHub user, I will be happy to do the aforementioned for you but would like to get your email address via PM so I can give credit to you and refer the author to you in case he has any questions.

In the mean-time, I will patch the version of the RF24 library that we bundle with the MySensors library and run some tests because I have seen the same problem. If I can confirm that your fix resolves the problem, then I will ask Henrik how he would like to handle the fix in the 1.3 launch time.

Nice work!

Best,
Bruce

A-lurker,

I have applied your patches but I still see intermittent presentation messages fail if the radio needs to be powered up…

Started sensor.
Relay=0, distance=1
Radio id stored in EEPROM Started sensor.
Relay=0, distance=1
Radio id stored in EEPROM was: 2
Relaying message back to gateway.
Tx: fr=2,to=0,la=2,ne=0,ci=255,mt=0,ty=17,cr=52: 1.2+
RF24::powerUp - powering up radio
Send failed.

Perhaps there is something else that needs to be done in order for the radio to fully initialize. Here are the changes that I implemented…

void RF24::powerUp(void)
{
  uint8_t cfg = read_register(CONFIG);

  // if not powered up then power up and wait for the radio to initialize
  if (!(cfg & _BV(PWR_UP)))
  {
     Serial.println("RF24::powerUp - powering up radio");
     write_register(CONFIG,read_register(CONFIG) | _BV(PWR_UP));
     delayMicroseconds(150);
  }
}

void RF24::startListening(void)
{

  // receiver on, transmitter off
  write_register(CONFIG, read_register(CONFIG) | _BV(PRIM_RX));

  // if not powered up already, power up the radio
  powerUp();

  write_register(STATUS, _BV(RX_DR) | _BV(TX_DS) | _BV(MAX_RT) );

  // Restore the pipe0 adddress, if exists
  if (pipe0_reading_address)
    write_register(RX_ADDR_P0, reinterpret_cast<const uint8_t*>(&pipe0_reading_address), 5);

#if 0
  // Flush buffers
  flush_rx();
  flush_tx();
#endif

  // Go!
  ce(HIGH);

  // wait for the radio to come up (130us actually only needed)
  delayMicroseconds(130);
}

void RF24::startWrite( const void* buf, uint8_t len, const bool multicast )
{
  // receiver off, transmitter on
  write_register(CONFIG, read_register(CONFIG) & ~_BV(PRIM_RX));

  // if not powered up already, power up the radio
  powerUp();

  // Send the payload - Unicast (W_TX_PAYLOAD) or multicast (W_TX_PAYLOAD_NO_ACK)
  write_payload( buf, len,
                 multicast?static_cast<uint8_t>(W_TX_PAYLOAD_NO_ACK):static_cast<uint8_t>(W_TX_PAYLOAD) ) ;

  // Allons!
  ce(HIGH);
  delayMicroseconds(10);
  ce(LOW);
}

For comparison, the presentation message is successful if the radio is ready…

Started sensor.
Relay=0, distance=1
Radio id stored in EEPROM Started sensor.
Relay=0, distance=1
Radio id stored in EEPROM was: 2
Relaying message back to gateway.
Tx: fr=2,to=0,la=2,ne=0,ci=255,mt=0,ty=17,cr=52: 1.2+
Sent successfully

So I know you are close but the question is, why doesn’t the radio initialize the radio properly?

Henrik, perhaps we should move these RF24 troubleshooting posts to a separate thread?

Hi Bruce

Need to check this out too:

http://forum.micasaverde.com/index.php/topic,24152.msg165828.html#msg165828

ie need this change as well in Sensor::sendWrite()

if (!broadcast && (radioId == GATEWAY_ADDRESS)) {

I’m not sure how the above code is meant to work - the suggested fix is just my guess at it. In Sensor::sendWrite the result boolean returned by RF24::write should be put into action. I believe that if you do a print statement on it you will find the transmit was actually OK and the “Send failed.” msg is incorrect. You can check in the Vera log file to see if the msg is getting to its destination.


ok = RF24::write(&message, min(MAX_MESSAGE_LENGTH, sizeof(message.header) + length), broadcast);

// print ok

Also need to remove this in RF24::startListening()

// wait for the radio to come up (130us actually only needed) delayMicroseconds(130);

Ok, so I have incorporated your additional changes however I can still cause the presentation messages to intermittently fail to send… That said, perhaps these are now legitimate failures because the message is not sent according to the RF24::write() return status but is that due to an initialized / powered-up radio still?

Started sensor.
Relay=0, distance=1
Radio id stored in EEPROM was: 2
Relaying message back to gateway.
Tx: fr=2,to=0,la=2,ne=0,ci=255,mt=0,ty=17,cr=52: 1.2+
Sensor::sendWrite() - return value = false
Send failed.

Here are the changes that I applied.

RF24.cpp

diff --git a/libraries/RF24/RF24.cpp b/libraries/RF24/RF24.cpp
index 5f6c41d..28f45c5 100644
--- a/libraries/RF24/RF24.cpp
+++ b/libraries/RF24/RF24.cpp
@@ -402,7 +402,13 @@ void RF24::begin(void)
 
 void RF24::startListening(void)
 {
-  write_register(CONFIG, read_register(CONFIG) | _BV(PWR_UP) | _BV(PRIM_RX));
+
+  // receiver on, transmitter off
+  write_register(CONFIG, read_register(CONFIG) | _BV(PRIM_RX));
+
+  // if not powered up already, power up the radio
+  powerUp();
+
   write_register(STATUS, _BV(RX_DR) | _BV(TX_DS) | _BV(MAX_RT) );
 
   // Restore the pipe0 adddress, if exists
@@ -417,9 +423,6 @@ void RF24::startListening(void)
 
   // Go!
   ce(HIGH);
-
-  // wait for the radio to come up (130us actually only needed)
-  delayMicroseconds(130);
 }
 
 /****************************************************************************/
@@ -442,8 +445,15 @@ void RF24::powerDown(void)
 
 void RF24::powerUp(void)
 {
-  write_register(CONFIG,read_register(CONFIG) | _BV(PWR_UP));
-  delayMicroseconds(150);
+  uint8_t cfg = read_register(CONFIG);
+  
+  // if not powered up then power up and wait for the radio to initialize
+  if (!(cfg & _BV(PWR_UP)))
+  {
+     //printf("RF24::powerUp - powering up radio\n");
+     write_register(CONFIG,read_register(CONFIG) | _BV(PWR_UP));
+     delayMicroseconds(150);
+  }
 }
 
 /******************************************************************/
@@ -509,8 +519,11 @@ bool RF24::write( const void* buf, uint8_t len, const bool multicast )
 
 void RF24::startWrite( const void* buf, uint8_t len, const bool multicast )
 {
-  // Transmitter power-up
-  write_register(CONFIG, ( read_register(CONFIG) | _BV(PWR_UP) ) & ~_BV(PRIM_RX) );
+  // receiver off, transmitter on
+  write_register(CONFIG, read_register(CONFIG) & ~_BV(PRIM_RX));
+
+  // if not powered up already, power up the radio
+  powerUp();
 
   // Send the payload - Unicast (W_TX_PAYLOAD) or multicast (W_TX_PAYLOAD_NO_ACK)
   write_payload( buf, len,

Sensor.cpp

git diff Sensor.cpp 
diff --git a/libraries/MySensors/Sensor.cpp b/libraries/MySensors/Sensor.cpp
index 2908105..6d1e1aa 100644
--- a/libraries/MySensors/Sensor.cpp
+++ b/libraries/MySensors/Sensor.cpp
@@ -226,11 +226,12 @@ boolean Sensor::sendWrite(uint8_t dest, message_s message, int length) {
 //     int retry = WRITE_RETRY;
        RF24::stopListening();
        RF24::openWritingPipe(TO_ADDR(dest));
-       RF24::write(&message, min(MAX_MESSAGE_LENGTH, sizeof(message.header) + length), broadcast);
+       ok = RF24::write(&message, min(MAX_MESSAGE_LENGTH, sizeof(message.header) + length), broadcast);
+        debug(PSTR("Sensor::sendWrite() - return value = %s\n"), ok ? "true" : "false" );
        RF24::startListening();
        RF24::closeReadingPipe(WRITE_PIPE); // Stop listening to write-pipe after transmit
 
-       if (!broadcast) {
+       if (!broadcast && (radioId == GATEWAY_ADDRESS)) {
                // ---------------- WAIT FOR ACK ------------------
                 unsigned long startedWaiting = millis();
                 bool timeout = false;
@@ -238,6 +239,7 @@ boolean Sensor::sendWrite(uint8_t dest, message_s message, int length) {
                 while ( !RF24::available() && !timeout ) {
                        if (millis() - startedWaiting > 100 ) {
                                timeout = true;
+                               debug(PSTR("Transmit: timeout\n"));
                                ok = false;
                        }
                 }
@@ -246,10 +248,12 @@ boolean Sensor::sendWrite(uint8_t dest, message_s message, int length) {
                        uint8_t idest;
                        RF24::read( &idest, sizeof(uint8_t));
                        if (dest != idest) {
+                               debug(PSTR("Transmit: size problem\n"));
                                ok = false;
                        }
                } else {
                        ok = false;
+                       debug(PSTR("Transmit: general fail\n"));
                }
                //--------------------
        }

I have to call it a night but I am going to commit the changes to a test branch called GW_PRESENTATION-diag and pass it off to Henrik to take a look.

If you want to confirm that I incorporate all your suggested changes, take a look at the branch in https://github.com/bblacey/Arduino/tree/GW_PRESENTATION-diag or download a zip of the branch from https://github.com/bblacey/Arduino/archive/GW_PRESENTATION-diag.zip

Hopefully Henrik will have some insight into the root cause and remedy.

Thanks,
Bruce

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.

[quote=“a-lurker, post:12, topic:180325”]I’m not sure how the above code is meant to work - the suggested fix is just my guess at it. In Sensor::sendWrite the result boolean returned by RF24::write should be put into action. I believe that if you do a print statement on it you will find the transmit was actually OK and the “Send failed.” msg is incorrect. You can check in the Vera log file to see if the msg is getting to its destination.

[code]

ok = RF24::write(&message, min(MAX_MESSAGE_LENGTH, sizeof(message.header) + length), broadcast);

// print ok

[/code][/quote]

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.

[quote=“a-lurker, post:9, topic:180325”]Presentation and power up problem:

It turns out that the very first write to the radio does not implement the required power up delay. The problem is actually alluded to in the Dallas Temperature sketch and some others:

gw.powerUp(); // Powerup introduces a small delay (which is missing in radio.write powerup)

…[/quote]

I think You are really on to something here A-lurker, thanks for the investigation. Did you verify it yourself?

Bruce, did you look at the receiving side? As it could be the soft-ack thing not working reliably.

Ok,

We have now incorporated A-lurkers proposed changes to the RF24 library. But we had to increase the power-up delay a bit. Mine and Bruces findings shows that the delay seems to depend on what type of decoupling capacitor used.

We also introduced a small delay before sending ack messages to to let ack-receiver switch to listening mode.

Hope this will help everyone having problems with presentation and first send after power-up.

Please update and feedback your results!

Will do. Thanks everyone for looking in to this :wink:

Does the GW allso need to be updated?

Given that we are mucking with the core messaging, it would be helpful if you those who are testing this latest version would enable #define DEBUG in Config.h and report your test results to ensure we haven’t introduced any messaging regressions.

/libraries/MySensors/Config.h

#define DEBUG

If you see any send failures, please post the logs from the sensor and the Vera gateway.

The good news is that I now got the parent node for my energy pulse sensor and it is reporting fine. I’m not using sleep mode on this one.
The bad news is I also updated a soilmoistsensor and I was not able to get the parent node and it seems like it only reports the status at startup. This sensor use sleep mode. I’ll see if I can get some loging from this one tomorrow. Have a good night :wink:

[quote=“korttoma, post:19, topic:180325”]The good news is that I now got the parent node for my energy pulse sensor and it is reporting fine. I’m not using sleep mode on this one.
The bad news is I also updated a soilmoistsensor and I was not able to get the parent node and it seems like it only reports the status at startup. This sensor use sleep mode. I’ll see if I can get some loging from this one tomorrow. Have a good night ;)[/quote]

I would also be interesting to know if and what type of capacitor you have on the two sensors?

BR
Henrk