@TimO thanks for the pointers. All my nodes were working ok but via a lot of playing around I found a repeater node that also runs a light dimmer (which the light dimmer worked fine and so did all of the repeating functions) was constantly sending an ID request. I disabled the repeater function and flashed it back and it is now not sending these requests. I then deployed another (better) repeater node into the same area and did not catch anymore ID requests so it would appear the repeater was causing the issue. I did flash it again with repeater on but it went bad again so gave that away and now have a different repeater serving that part of the property and no more weird ID requests. Thanks again for your help and continuing work on the binding.

PS: Is there somewhere that we can always get the latest JAR files from, I find I have to troll posts to find links?

@TimO There is no given_ids.cached file - there is a given_ids_mysensors_bridge-eth_gateway.cached file and it contains:

[0,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50,51,52,53,54,55,56,57,58,59,60,61,62,63,64,65,66,67,68,69,70,71,72,73,74,75,76,77,78,79,80,81,82,83,84,85,86,87,88,89,90,91,92,93,94,95,96,97,98,99,100,101,102,103,104,105,106,107,108,109,110,111,112,113,114,115,116,117,118,119,120,121,122,123,124,125,126,127,128,129,130,131,132,133,134,135,136,137,138,139,140,141,142,143,144,145,146,147,148,149,150,151,152,153,154,155,156,157,158,159,160,161,162,163,164,165,166,167,168,169,170,171,172,173,174,175,176,177,178,179,180,181,182,183,184,185,186,187,188,189,190,191,192,193,194,195,196,197,198,199,200,201,202,203,204,205,206,207,208,209,210,211,212,213,214,215,216,217,218,219,220,221,222,223,224,225,226,227,228,229,230,231,232,233,234,235,236,237,238,239,240,241,242,243,244,245,246,247,248,249,250,251,252,253,254]

I have fixed ID on all my nodes and have not changed anything for a long time.

I have just upgraded my Docker based RPI Openhab to 2.5.6 and updated the jar to org.openhab.binding.mysensors-2.5.0-SNAPSHOT.jar

Since I did this and tail the openhab log file I get this:

2020-07-28 16:24:38.576 [DEBUG] [rsAbstractConnection$MySensorsReader] - Message from gateway received: 255;255;3;0;3;0
2020-07-28 16:24:38.580 [INFO ] [rs.internal.gateway.MySensorsGateway] - ID Request received
2020-07-28 16:24:38.588 [ERROR] [rs.internal.gateway.MySensorsGateway] - No more IDs available for this node, you could try cleaning cache file

My Node:3 is a multi function, Humidity, Temp, Light, Rain and Barometric sensor. I believe 255 is used for some other comms as per the docs it is not recommended to be used for nodes. So why this being constantly logged, do I need to add a dummy node 255 or something?

Oh and I have tried doing what it says and cleaning the cache file, I deleted both files in the userdata/logs/mysensors/cache and restarted my docker container.

@mfalkvidd My thoughts are change the Buying Guide and related text to the BME it is a much better sensor with Humidity included and is only slightly more $. I have ordered some BME's and will be testing the provided sketch in due course.

@mfalkvidd Yes seems right but the most confusing part and the one I stumbled on is that on the page https://www.mysensors.org/build/pressure for the sensor the Shopping Guide points you at the BMP280 which as we are identifying is not the relevant item for the project - I followed the provided link and purchased the sensor (after waiting for weeks for delivery) only to find it does not work at all (as I suspect my be the case for @Andrew-Maynard as the sensors does not init and the loop does not run) and hence my code was needed to run the node using the item shown in the shopping guide.

I could not make the example BME280 sketch work either and upon investigation the code is not for the standard BME280 it is for the BME280 library by Embedded Adventures - https://github.com/embeddedadventures/BME280. This device is not the same as the cheaper standard BME280 as linked on the forum page. The Embedded Adventure one has humidity, the standard BME280 does not.

Anyway I researched and converted some other BME280 code I found from the SFE_BMP180 library, coupled the Forecast code and created the following sketch for the BME280. You will need to install the SFE_BMP180.h library using library manager

/**
 * The MySensors Arduino library handles the wireless radio link and protocol
 * between your home built sensors/actuators and HA controller of choice.
 * The sensors forms a self healing radio network with optional repeaters. Each
 * repeater and gateway builds a routing tables in EEPROM which keeps track of the
 * network topology allowing messages to be routed to nodes.
 *
 * Created by Henrik Ekblad <henrik.ekblad@mysensors.org>
 * Copyright (C) 2013-2015 Sensnology AB
 * Full contributor list: https://github.com/mysensors/Arduino/graphs/contributors
 *
 * Documentation: http://www.mysensors.org
 * Support Forum: http://forum.mysensors.org
 *
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License
 * version 2 as published by the Free Software Foundation.
 *
 *******************************
 *
 * REVISION HISTORY
 * 
 */

// Enable debug prints
#define MY_DEBUG

// Enable and select radio type attached 
#define MY_RADIO_NRF24
// #define MY_RF24_CHANNEL 82

// #define MY_NODE_ID 22 //uncomment this line to assign a static ID

#include <MySensors.h>  

#define CHILD_ID_BARO  0
#define CHILD_ID_TEMP 1

static bool metric = true;

// Sleep time between sensor updates (in milliseconds)
unsigned long UPDATE_INTERVAL = 60000;

#define ALTITUDE 28.0 // Altitude  in meters

#define GENERATE_FORECAST

#define CONVERSION_FACTOR (1.0/10.0)     // used by forecast algorithm to convert from Pa to kPa, by dividing hPa by 10.
#ifdef GENERATE_FORECAST      //  Below you will find a lot of variables used by the forecast algorithm.
  const char *weather[] = { "stable", "sunny", "cloudy", "unstable", "thunderstorm", "unknown" };
  enum FORECAST
  {
    STABLE = 0,             // "Stable Weather Pattern"
    SUNNY = 1,              // "Slowly rising Good Weather", "Clear/Sunny "
    CLOUDY = 2,             // "Slowly falling L-Pressure ", "Cloudy/Rain "
    UNSTABLE = 3,           // "Quickly rising H-Press",     "Not Stable"
    THUNDERSTORM = 4,       // "Quickly falling L-Press",    "Thunderstorm"
    UNKNOWN = 5             // "Unknown (More Time needed)
  };
  int lastForecast = -1;        // Stores the previous forecast, so it can be compared with a new forecast.
  const int LAST_SAMPLES_COUNT = 5;
  float lastPressureSamples[LAST_SAMPLES_COUNT];
  int minuteCount = 0;        // Helps the forecst algorithm keep time.
  bool firstRound = true;       // Helps the forecast algorithm recognise if the sensor has just been powered up.
  float pressureAvg;        // Average value is used in forecast algorithm.
  float pressureAvg2;       // Average after 2 hours is used as reference value for the next iteration.
  float dP_dt;          // Pressure delta over time
#endif

#include <SFE_BMP180.h>

static SFE_BMP180 pressure;

static MyMessage msgBaro(CHILD_ID_BARO, V_PRESSURE );
static MyMessage msgTemp(CHILD_ID_TEMP, V_TEMP);
#ifdef GENERATE_FORECAST
  MyMessage msgForecast(CHILD_ID_BARO, V_FORECAST);
#endif

void presentation()  
{ 
  // Send the sketch info to the gateway
  sendSketchInfo("TemperatureAndPressure", "1.0");

  // Present sensors as children to gateway
  present(CHILD_ID_BARO, S_BARO, "Pressure");
  wait(50);
  present(CHILD_ID_TEMP, S_TEMP, "Temperature");
  wait(50);
  metric = getControllerConfig().isMetric;
}

void setup()
{
  pressure.begin();
}


void loop()      
{  
  char status;
  double T,P,p0,a;
  unsigned long currentMillis = millis();

  status = pressure.startTemperature();
  if (status != 0) { wait(status); }
  status = pressure.getTemperature(T);
  if (status != 0)
  {
    // Print out the measurement:
    Serial.print("temperature: ");
    Serial.print(T,2);
    Serial.print(" deg C, ");
    Serial.print((9.0/5.0)*T+32.0,2);
    Serial.println(" deg F");
    send(msgTemp.set(T, 2));
  }
  // Start a pressure measurement:
  // The parameter is the oversampling setting, from 0 to 3 (highest res, longest wait).
  // If request is successful, the number of ms to wait is returned.
  // If request is unsuccessful, 0 is returned.
  status = pressure.startPressure(3);
  if (status != 0) { wait(status); }
  status = pressure.getPressure(P,T);
  if (status != 0)
  {
    // Print out the measurement:
    Serial.print("absolute pressure: ");
    Serial.print(P,2);
    Serial.print(" mb, ");
    Serial.print(P*0.0295333727,2);
    Serial.println(" inHg");
    send(msgBaro.set(P, 2));        
  }
  
#ifdef GENERATE_FORECAST      
    int forecast = sample(P);            // Run the forecast function with a new pressure update.

    // Send forecast
    if (forecast != lastForecast) {
      Serial.println("BME280 - Sending the latest forecast to the gateway.");      
      send(msgForecast.set(weather[forecast]));
      lastForecast = forecast;
    }
#endif

  // Sleep until next update to save energy but check for how long to sleep based on delays in getting data
  unsigned long sleeptime = UPDATE_INTERVAL  - (millis() - currentMillis); // How much time has passed already during the calculating? Subtract that from the intended interval time.
  wait(sleeptime); 
}



#ifdef GENERATE_FORECAST
// These functions are only included if the forecast function is enables. The are used to generate a weater prediction by checking if the barometric pressure is rising or falling over time.

float getLastPressureSamplesAverage()
{
  float lastPressureSamplesAverage = 0;
  for (int i = 0; i < LAST_SAMPLES_COUNT; i++) {
    lastPressureSamplesAverage += lastPressureSamples[i];
  }
  lastPressureSamplesAverage /= LAST_SAMPLES_COUNT;

  return lastPressureSamplesAverage;
}


// Forecast algorithm found here
// http://www.freescale.com/files/sensors/doc/app_note/AN3914.pdf
// Pressure in hPa -->  forecast done by calculating kPa/h
int sample(float pressure) {
  // Calculate the average of the last n minutes.
  int index = minuteCount % LAST_SAMPLES_COUNT;
  lastPressureSamples[index] = pressure;

  minuteCount++;
  if (minuteCount > 185) {
    minuteCount = 6;
  }

  if (minuteCount == 5) {
    pressureAvg = getLastPressureSamplesAverage();
  }
  else if (minuteCount == 35) {
    float lastPressureAvg = getLastPressureSamplesAverage();
    float change = (lastPressureAvg - pressureAvg) * CONVERSION_FACTOR;
    if (firstRound) { // first time initial 3 hour 
      dP_dt = change * 2; // note this is for t = 0.5hour
    }
    else {
      dP_dt = change / 1.5; // divide by 1.5 as this is the difference in time from 0 value.
    }
  }
  else if (minuteCount == 65) {
    float lastPressureAvg = getLastPressureSamplesAverage();
    float change = (lastPressureAvg - pressureAvg) * CONVERSION_FACTOR;
    if (firstRound) { //first time initial 3 hour
      dP_dt = change; //note this is for t = 1 hour
    }
    else {
      dP_dt = change / 2; //divide by 2 as this is the difference in time from 0 value
    }
  }
  else if (minuteCount == 95) {
    float lastPressureAvg = getLastPressureSamplesAverage();
    float change = (lastPressureAvg - pressureAvg) * CONVERSION_FACTOR;
    if (firstRound) { // first time initial 3 hour
      dP_dt = change / 1.5; // note this is for t = 1.5 hour
    }
    else {
      dP_dt = change / 2.5; // divide by 2.5 as this is the difference in time from 0 value
    }
  }
  else if (minuteCount == 125) {
    float lastPressureAvg = getLastPressureSamplesAverage();
    pressureAvg2 = lastPressureAvg; // store for later use.
    float change = (lastPressureAvg - pressureAvg) * CONVERSION_FACTOR;
    if (firstRound) { // first time initial 3 hour
      dP_dt = change / 2; // note this is for t = 2 hour
    }
    else {
      dP_dt = change / 3; // divide by 3 as this is the difference in time from 0 value
    }
  }
  else if (minuteCount == 155) {
    float lastPressureAvg = getLastPressureSamplesAverage();
    float change = (lastPressureAvg - pressureAvg) * CONVERSION_FACTOR;
    if (firstRound) { // first time initial 3 hour
      dP_dt = change / 2.5; // note this is for t = 2.5 hour
    } 
    else {
      dP_dt = change / 3.5; // divide by 3.5 as this is the difference in time from 0 value
    }
  }
  else if (minuteCount == 185) {
    float lastPressureAvg = getLastPressureSamplesAverage();
    float change = (lastPressureAvg - pressureAvg) * CONVERSION_FACTOR;
    if (firstRound) { // first time initial 3 hour
      dP_dt = change / 3; // note this is for t = 3 hour
    } 
    else {
      dP_dt = change / 4; // divide by 4 as this is the difference in time from 0 value
    }
    pressureAvg = pressureAvg2; // Equating the pressure at 0 to the pressure at 2 hour after 3 hours have past.
    firstRound = false; // flag to let you know that this is on the past 3 hour mark. Initialized to 0 outside main loop.
  }

  int forecast = UNKNOWN;
  if (minuteCount < 35 && firstRound) { //if time is less than 35 min on the first 3 hour interval.
    forecast = UNKNOWN;
  }
  else if (dP_dt < (-0.25)) {
    forecast = THUNDERSTORM;
  }
  else if (dP_dt > 0.25) {
    forecast = UNSTABLE;
  }
  else if ((dP_dt > (-0.25)) && (dP_dt < (-0.05))) {
    forecast = CLOUDY;
  }
  else if ((dP_dt > 0.05) && (dP_dt < 0.25))
  {
    forecast = SUNNY;
  }
  else if ((dP_dt >(-0.05)) && (dP_dt < 0.05)) {
    forecast = STABLE;
  }
  else {
    forecast = UNKNOWN;
  }

  // uncomment when debugging
  //Serial.print(F("BME280 - Forecast at minute "));
  //Serial.print(minuteCount);
  //Serial.print(F(" dP/dt = "));
  //Serial.print(dP_dt);
  //Serial.print(F("kPa/h --> "));
  //Serial.println(weather[forecast]);

  return forecast;
}
#endif

I am investigating a problem I have found with I think openHAB but I am not sure if this issue is not related to the Gateway code of 2.3.0.
When a node performs a requestTime() I am seeing this reported:

2018-10-09 10:47:13.337 [INFO ] [rs.internal.gateway.MySensorsGateway] - I_TIME request received from 2, answering...

Looks perfect and the node receives the time however I was curious as to why sometimes the node would receive GMT and at other times my local timezone GMT+8. I decided to run the gateway via MYSContoller so I could monitor and log the traffic and I have found the problem. When the Gateway receives the request it responds twice within a few ms of each other, for what reason I do not know but the first response send the local time zone response (GMT+8) and the second is a GMT response. The logs from MYSController for the above report are as follows:

318857 9/10/2018 10:47:19 RX 2 - Irrigation Ctrl (2) INTERNAL C_INTERNAL NO I_TIME
318858 9/10/2018 10:47:19 TX 2 - Irrigation Ctrl (2) INTERNAL C_INTERNAL NO I_TIME 1539082039
318859 9/10/2018 10:47:19 TX 2 - Irrigation Ctrl (2) INTERNAL C_INTERNAL NO I_TIME "1539053233

"
Note the quotes where picked up in the copy and paste (I did this several times) so it looks like the body was changed to a string type but I also caught this in the MYSController Debug:
9/10/2018 10:47:19 RX 2;255;3;0;1;
9/10/2018 10:47:19 INFO Reply time request
9/10/2018 10:47:19 TX 2;255;3;0;1;1539082039
9/10/2018 10:47:19 FWD 2;255;3;0;1;1539053233
9/10/2018 10:47:19 TX 2;255;3;0;1;1539053233

So I am curious as to where the FWD comes from and why the response body has changed between the TX, FWD & TX?

@itbeyond said in openHab binding 2.4.0 Variable Problem ( 2.4.0.201806211605):

Bug reported to Github issues at: https://github.com/tobof/openhab2-addons/issues/126

@itbeyond said in openHAB binding 2.4.0 I_TIME Duplicates & Wrong Times:

Bug report submitted in issues https://github.com/tobof/openhab2-addons/issues/125

I also use the lookup in PaperUI to be sure but it looks like you have added the thing in PaperUI from the inbox. What I would do is delete from PaperUI both nodes. If it is as you say setup in the .things files correctly you will not be able to delete it from PaperUI it will report a problem with any things that are setup in the manual things files.

I have been using the 2.4.0 binding for a few months now and was going to report this issue a while back however I have now seen exactly what is going on. When a node performs a requestTime() I am seeing this reported in the logtail correctly as:

2018-10-09 09:00:01.310 [INFO ] [rs.internal.gateway.MySensorsGateway] - I_TIME request received from 3, answering...

Looks perfect and the node receives the time however I was curious as to why sometimes the node would receive GMT and at other times my local timezone GMT+8. I decided to run the gateway via MYSContoller so I could monitor and log the traffic and I have found the problem. When the Gateway receives the request it responds twice within a few ms of each other, for what reason I do not know but the first response send the local time zone response (GMT+8) and the second is a GMT response. The logs for the above logtail report are as follows:

314155 9/10/2018 9:00:06 RX 3 - Rain Gauge (3) INTERNAL C_INTERNAL NO I_TIME
314156 9/10/2018 9:00:06 TX 3 - Rain Gauge (3) INTERNAL C_INTERNAL NO I_TIME 1539075607
314163 9/10/2018 9:00:07 TX 3 - Rain Gauge (3) INTERNAL C_INTERNAL NO I_TIME "1539046801"

Now the above is a copy and paste so not even sure where the quotes came from (cannot see them in MYSController - but they copied from the GMT response only). I was not quick enough the capture the details in the MYSController Debug area. However you will see the two sets of results returned from the one request within a few ms of each other. If you do the maths you will note that they are 28806 ms apart - 8 hours and some 6 seconds. This is the difference between GMT and my local time so it sends Local first then GMT which does an override in my node. In my nodes I have coded to add 28800 to the received time to try to get around the problem however if my node misses the second send it will be ahead by 8 hours.

Anyway I am not sure why this is occurring and it does seem a lot like a bug of some sort.

For completeness my bridge binding is as follows:

Bridge mysensors:bridge-eth:gateway [ ipAddress="192.168.100.136", tcpPort=5003, sendDelay=200,  startupCheckEnabled=true,  networkSanCheckEnabled=true, networkSanCheckInterval=1, networkSanCheckConnectionFailAttempts=1 ] {
  light       Courtyard_Pond_Pump      "Courtyard Pond Pump" @ "Courtyard"      [ nodeId=1, childId=1 ] 
  light       Courtyard_Garden_Lights  "Courtyard Garden Lights" @ "Courtyard"  [ nodeId=1, childId=2 ]
  
  light       Water_All_Zones  "Water - All Zones"  @ "Backyard"    [ nodeId=2, childId=0 ] 
  light       Water_Zone_1     "Water - Zone 1"     @ "Backyard"    [ nodeId=2, childId=1 ]
  light       Water_Zone_2     "Water - Zone 2"     @ "Backyard"    [ nodeId=2, childId=2 ]
  light       Water_Zone_3     "Water - Zone 3"     @ "Backyard"    [ nodeId=2, childId=3 ]  
  light       Water_Zone_4     "Water - Zone 4"     @ "Backyard"    [ nodeId=2, childId=4 ]
  light       Water_Zone_5     "Water - Zone 5"     @ "Backyard"    [ nodeId=2, childId=5 ]
  light       Water_Zone_6     "Water - Zone 6"     @ "Backyard"    [ nodeId=2, childId=6 ]

  humidity    Courtyard_Outside_Humidity      "Courtyard Outside Humidity" @ "Courtyard" [ nodeId=3, childId=0 ]
  temperature Courtyard_Outside_TempDHT       "Courtyard Outside Temp"     @ "Courtyard" [ nodeId=3, childId=1 ]
  light-level Courtyard_Outside_Light         "Courtyard Outside Light"    @ "Courtyard" [ nodeId=3, childId=2 ]
  rain        Courtyard_Outside_Rain          "Courtyard Outside Rain"     @ "Courtyard" [ nodeId=3, childId=3 ]  
  motion      Courtyard_Outside_RainDetected  "Courtyard Rain Detected"    @ "Courtyard" [ nodeId=3, childId=4 ]
  baro        Courtyard_Outside_Baro          "Courtyard Outside Baro"     @ "Courtyard" [ nodeId=3, childId=5 ] 
  temperature Courtyard_Outside_Temp          "Courtyard Outside Temp"     @ "Courtyard" [ nodeId=3, childId=6 ] 

  cover       Courtyard_Door_Blind  "Courtyard Door Blind"  @ "Courtyard" [ nodeId=4, childId=1 ]
  cover       Office_Front_Blinds   "Office Front Blinds"   @ "Office"    [ nodeId=4, childId=2 ]
  cover       Office_Side_Blinds    "Office Side Blinds"    @ "Office"    [ nodeId=4, childId=3 ]
  cover       Courtyard_LHS_Blinds   "Courtyard LHS Blinds" @ "Courtyard" [ nodeId=4, childId=4 ]
  cover       Courtyard_RHS_Blinds   "Courtyard RHS Blinds" @ "Courtyard" [ nodeId=4, childId=5 ]
  
  power       Power_Phase1  "Energy Phase 1"  @ "Garage"  [ nodeId=5, childId=0 ]
  power       Power_Phase2  "Energy Phase 2"  @ "Garage"  [ nodeId=5, childId=1 ]
  power       Power_Phase3  "Energy Phase 3"  @ "Garage"  [ nodeId=5, childId=2 ]
  power       Power_Main    "Energy Main"     @ "Garage"  [ nodeId=5, childId=8 ]

  scene       MasterBedroom_SceneController_8Way  "MasterBedroom_SceneController_8Way" @ "Bedroom"  [ nodeId=6, childId=0 ]

  light       Entry_FrontGarden_Lights    "Power Socket Relay" @ "Entry"  [ nodeId=7, childId=1 ]

  dimmer      Lounge_Front_Lights   "Lounge Front Lights"   @ "Lounge"  [ nodeId=8, childId=0 ] 
  dimmer      Lounge_Centre_Lights  "Lounge Centre Lights"  @ "Lounge"  [ nodeId=8, childId=1 ]
  dimmer      Lounge_Left_Lights    "Lounge Left Lights"    @ "Lounge"  [ nodeId=8, childId=2 ]
  dimmer      Lounge_Right_Lights   "Lounge Right Lights"   @ "Lounge"  [ nodeId=8, childId=3 ]

  light       MasterBedroom_Main_Light    "Bedroom Main Light"          @ "Bedroom" [ nodeId=9, childId=0 ]
  light       MasterBedroom_Robe_Light    "MBedroom Robe Light"         @ "Bedroom" [ nodeId=9, childId=1 ]
  light       MasterBedroom_Bedside_David "MasterBedroom Bedside David" @ "Bedroom" [ nodeId=9, childId=2 ]  
  light       MasterBedroom_Bedside_Shel  "MasterBedroom Bedside Shel"  @ "Bedroom" [ nodeId=9, childId=3 ]
  temperature MasterBedroom_Roof_Temp     "MasterBedroom Roof Temp"     @ "Bedroom" [ nodeId=9, childId=4 ]

  motion      Garage_Landcruiser    "Garage Landcruiser"  @ "Garage" [ nodeId=10, childId=1 ]
  motion      Garage_CLA250         "Garage CLA250"       @ "Garage" [ nodeId=10, childId=2 ]
  light       Garage_Door           "Garage Door"         @ "Garage" [ nodeId=10, childId=3 ] 
  temperature Garage_Internal_Temp  "Garage Temp"         @ "Garage" [ nodeId=10, childId=4 ]
  
  light       Backyard_Pool_Pump      "Backyard Pool Pump"     @ "Backyard" [ nodeId=11, childId=1 ]
  light       Backyard_Garden_Lights  "Backyard Garden Lights" @ "Backyard" [ nodeId=11, childId=2 ]

  dimmer      MasterBedroom_Ensuite_Light "MasterBedroom Ensuite Light" @ "Bedroom"  [ nodeId=12, childId=0 ] 
  light       MasterBedroom_Ensuite_Fan   "MasterBedroom Ensuite Fan"   @ "Bedroom" [ nodeId=12, childId=1 ]
  light       MasterBedroom_Ensuite_Heat1 "MasterBedroom Ensuite Heat1" @ "Bedroom" [ nodeId=12, childId=2 ]
  light       MasterBedroom_Ensuite_Heat2 "MasterBedroom Ensuite Heat2" @ "Bedroom" [ nodeId=12, childId=3 ]

  light       Office_Door   "Office Door Controller" @ "Office"  [ nodeId=13, childId=1 ]

  light       Bathroom_Main_TowelRail    "Power Socket Relay" @ "Bathroom"  [ nodeId=14, childId=1 ]

  light       Hallway_Bedroom_Lights    "Hallway_Bedroom_Lights"  @ "Hallways"  [ nodeId=15, childId=0 ]
  light       Backyard_PoolSpot_Light   "Backyard PoolSpot Light" @ "Backyard"  [ nodeId=15, childId=1 ]
  light       Kitchen_Pantry_Lights     "Kitchen Pantry Lights"   @ "Kitchen"   [ nodeId=15, childId=2 ]
  light       Hallway_FrontDoor_Lights "Hallway_FrontDoor_Lights" @ "Hallways"  [ nodeId=15, childId=3 ]
  temperature Kitchen_Roof_Temp       "Kitchen Roof Temp"         @ "Kitchen"   [ nodeId=15, childId=4 ]

  dimmer      Kitchen_WineRack_Lights   "Kitchen WineRack Lights" @ "Kitchen"  [ nodeId=16, childId=0 ] 

  light       Bathroom_Ensuite_TowelRail    "Power Socket Relay" @ "Bathroom"  [ nodeId=18, childId=1 ]

  dimmer      Alfresco_Outer_Lights "Alfresco Outer Lights" @ "Alfresco"  [ nodeId=19, childId=0 ] 
  dimmer      Alfresco_Inner_Lights "Alfresco Inner Lights" @ "Alfresco"  [ nodeId=19, childId=1 ]
  dimmer      Backyard_Eve_Lights   "Backyard Eve Lights"   @ "Backyard"  [ nodeId=19, childId=2 ]
  dimmer      Kitchen_Main_Lights   "Kitchen Main Lights"   @ "Kitchen"   [ nodeId=19, childId=3 ]
  
  dimmer      Kitchen_Island_Light  "Kitchen Island Light" @ "Kitchen" [ nodeId=20, childId=0 ] 
  dimmer      Kitchen_Swirl_Light   "Kitchen Swirl Light"  @ "Kitchen" [ nodeId=20, childId=1 ]

  light       Desktop_Debug_Light   "Power Socket Relay" @ "Office"  [ nodeId=27, childId=1 ]

  motion      Kitchen_Pantry_PIR    "Kitchen Pantry PIR" @ "Kitchen" [ nodeId=100, childId=0 ]

  motion      MasterBedroom_Robe_PIR      "MasterBedroom Robe PIR"    @ "Bedroom" [ nodeId=101, childId=0 ]
  motion      MasterBedroom_Ensuite_PIR   "MasterBedroom Ensuite PIR" @ "Bedroom" [ nodeId=102, childId=0 ]
}

I have a number of nodes as you can see and 2, 4 & 9 all use time and have the same exact problem. If I reboot or setup a test case I always get two times returned from the one request and it always is Local followed by GMT. I guess a node based work around would be to trash the second result if received within 30 seconds or something but when playing with time it is not a simple method as millis() may change between loading.

Anyone else see this or now how to fix it?

@vladimir I really think you need to look at this in the serial monitor and add some serial.print lines in the associated places in the code to see what is going on.

@TimO I posted something in the thread https://forum.mysensors.org/topic/9346/getting-mysensors-mqtt-gateway-working-on-openhab-2-2-stable/40 but just did another full round of testing to be sure so adding a new thread to get the conversation started. I have just set a test node that sits on my desk and have added the var1 item to an already well working test node - it is a switch and was not using any vars etc. So I editted the node code and added a loop request for var1 every 30 seconds.

Here is the code for this node

/**
 * The MySensors Arduino library handles the wireless radio link and protocol
 * between your home built sensors/actuators and HA controller of choice.
 * The sensors forms a self healing radio network with optional repeaters. Each
 * repeater and gateway builds a routing tables in EEPROM which keeps track of the
 * network topology allowing messages to be routed to nodes.
 *
 * Created by Henrik Ekblad <henrik.ekblad@mysensors.org>
 * Copyright (C) 2013-2015 Sensnology AB
 * Full contributor list: https://github.com/mysensors/Arduino/graphs/contributors
 *
 * Documentation: http://www.mysensors.org
 * Support Forum: http://forum.mysensors.org
 *
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License
 * version 2 as published by the Free Software Foundation.
 *
 *******************************
 *
 * REVISION HISTORY
 * Version 1.0 - Henrik Ekblad
 *
 * DESCRIPTION
 * Example sketch showing how to control physical relays.
 * This example will remember relay state after power failure.
 * http://www.mysensors.org/build/relay
 */

// Enable debug prints to serial monitor
#define MY_DEBUG

// Enable and select radio type attached
#define MY_RADIO_NRF24
#define MY_RF24_CHANNEL 82
#define MY_RF24_IRQ_PIN 2
#define MY_RX_MESSAGE_BUFFER_FEATURE

#define MY_NODE_ID 27  // Set this to fix your Radio ID or use Auto

// Enable repeater functionality for this node
//#define MY_REPEATER_FEATURE
#define MY_TRANSPORT_SANITY_CHECK

#include <MySensors.h>

#define RELAY_1  3  // Arduino Digital I/O pin number for first relay (second on pin+1 etc)
#define NUMBER_OF_RELAYS 1 // Total number of attached relays
#define RELAY_ON 0  // GPIO value to write to turn on attached relay
#define RELAY_OFF 1 // GPIO value to write to turn off attached relay
#define RELAY_UNKNOWN 2

int CurrentState[] = {RELAY_UNKNOWN, RELAY_UNKNOWN, RELAY_UNKNOWN, RELAY_UNKNOWN};
int SetState[] = {RELAY_OFF, RELAY_OFF, RELAY_OFF, RELAY_OFF};

unsigned long requestVar1Last = millis();
unsigned long requestVar1Time = 30000;

MyMessage relayMsg(0, V_STATUS);

void before() {
  wdt_enable(WDTO_2S);
}

void setup()
{
  for (int sensor=1, pin=RELAY_1; sensor<=NUMBER_OF_RELAYS; sensor++, pin++) {
    // Then set relay pins in output mode
    pinMode(pin, OUTPUT);
    SetState[sensor] = RELAY_OFF;
    request(sensor, V_STATUS);
    delay(50); 
    request(sensor, V_VAR1);
  }
}
void presentation()
{
  // Send the sketch version information to the gateway and Controller
  sendSketchInfo("Power Socket (7)", "4.1");

  for (int sensor=1; sensor<=NUMBER_OF_RELAYS; sensor++) {
    // Register all sensors to gw (they will be created as child devices)
    present(sensor, S_BINARY);
  }
}

void loop()
{
  wdt_reset();
  
  for (int sensor=1, pin=RELAY_1; sensor<=NUMBER_OF_RELAYS; sensor++, pin++) {
      if (CurrentState[sensor] != SetState[sensor] && SetState[sensor] != RELAY_UNKNOWN) {
        digitalWrite(pin, SetState[sensor]?RELAY_ON:RELAY_OFF);
        CurrentState[sensor] = SetState[sensor];   
        resend(relayMsg.setSensor(sensor).set(CurrentState[sensor]), 5);  
      }
    }

  if (requestVar1Last + requestVar1Time < millis()) {
     request(1, V_VAR1);
     requestVar1Last = millis();
  }
}

void resend(MyMessage &msg, int repeats)
{
  int repeat = 1;
  int repeatdelay = 0;
  boolean sendOK = false;

  while ((sendOK == false) and (repeat < repeats)) {
    if (send(msg)) {
      sendOK = true;
    } else {
      sendOK = false;
      Serial.print("Send Failed: ");
      Serial.println(repeat);
      repeatdelay += 50;
    } repeat++; wait(repeatdelay);
  }
}

void receive(const MyMessage &message)
{
  int sensor = message.sensor;
  // We only expect one type of message from controller. But we better check anyway.
  if (message.type==V_STATUS) {
    // Change relay state
    SetState[sensor] = message.getBool();

    // Write some debug info
    Serial.print(F("Incoming change for sensor:"));
    Serial.print(message.sensor);
    Serial.print(F(", New status: "));
    Serial.println(message.getBool());
  }
  if (message.type == V_VAR1) {
    int variable1 = atoi(message.data);// RUN_ALL_ZONES time
    Serial.print(F("Recieved variable1: "));
    Serial.println(variable1);     
  }
}

I added the item to openHab ad follows:

Switch   Desktop_Debug_Light "Desktop Debug Light" <light> (gDevices,gRoom_Office) [ "iss:type:DevSwitch", "iss:room:Entry" ]  {channel="mysensors:light:gateway:Desktop_Debug_Light:status"}
Number  Desktop_Debug_Var1 "Desktop Debug Light- Var1 [%d]" <selfruntime>  (gDevices,gRoom_Office)   {channel="mysensors:light:gateway:Desktop_Debug_Light:var1"}

I used Paper UI and set the variable to 10 - this pushed the update to the node correctly. I then rebooted openHab which using persistance restores the variable 1 value back to 10 however when the node requests var1 from the controller after the reboot it receives 0. I have found this to be the same if I do an postUpdate. The var1 container on openHab has the 10 value in it I have confirmed this with a Rest API commnd the GET the item.

Here is the logs from the openHab log:tail and also the node I have added comments where the reboot happened and you will see the results:

2018-08-28 08:23:22.581 [.ItemChannelLinkAddedEvent] - Link 'Desktop_Debug_Var1-mysensors:light:gateway:Desktop_Debug_Light:var1' has been added.
2018-08-28 08:24:08.812 [ome.event.ItemCommandEvent] - Item 'Desktop_Debug_Var1' received command 10
2018-08-28 08:24:08.829 [vent.ItemStateChangedEvent] - Desktop_Debug_Var1 changed from NULL to 10
REBOOTED THE OPENHAB SERVER
2018-08-28 08:27:40.145 [temChannelLinkRemovedEvent] - Link 'Desktop_Debug_Var1 => mysensors:light:gateway:Desktop_Debug_Light:var1' has been removed.
2018-08-28 08:28:57.469 [.ItemChannelLinkAddedEvent] - Link 'Desktop_Debug_Var1-mysensors:light:gateway:Desktop_Debug_Light:var1' has been added.
2018-08-28 08:29:08.389 [vent.ItemStateChangedEvent] - Desktop_Debug_Var1 changed from NULL to 10.0

2280 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
2286 MCO:BGN:INIT OK,TSP=1
2290 TSF:MSG:SEND,27-27-0-0,s=1,c=1,t=2,pt=2,l=2,sg=0,ft=0,st=OK:1
2317 TSF:MSG:READ,0-0-27,s=1,c=1,t=2,pt=0,l=1,sg=0:1
Incoming change for sensor:1, New status: 1
2521 TSF:MSG:READ,0-0-27,s=1,c=1,t=24,pt=0,l=2,sg=0:10
Recieved variable1: 10
30002 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
30026 TSF:MSG:READ,0-0-27,s=1,c=1,t=24,pt=0,l=2,sg=0:10
Recieved variable1: 10
***** REBOOT OF OPENHAB SERVER *******
60010 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
90018 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
120026 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
150038 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
***** OPENHAB UP AGAIN ********
150090 TSF:MSG:READ,0-0-27,s=1,c=1,t=24,pt=0,l=1,sg=0:0
Recieved variable1: 0
180046 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
180071 TSF:MSG:READ,0-0-27,s=1,c=1,t=24,pt=0,l=1,sg=0:0
Recieved variable1: 0
210054 TSF:MSG:SEND,27-27-0-0,s=1,c=2,t=24,pt=0,l=0,sg=0,ft=0,st=OK:
210073 TSF:MSG:READ,0-0-27,s=1,c=1,t=24,pt=0,l=1,sg=0:0
Recieved variable1: 0

You can see the PaperUI update at 2018-08-28 08:24:08.829 which corresponds with the 30026 TSF:MSG:READ,0-0-27,s=1,c=1,t=24,pt=0,l=2,sg=0:10. I then rebooted and the server restored the value of 10 but the node continues to receive 0 and does so for ever - it never gets the value 10.

Here is the output of the item using the REST API which is taken well after the reboot and after many request(1,V_VAR1)'s is still reporting 0.

http://openhabianpi:8080/rest/items/Desktop_Debug_Var1
{
  "link": "http://openhabianpi:8080/rest/items/Desktop_Debug_Var1",
  "state": "10.0",
  "stateDescription": {
    "pattern": "%d",
    "readOnly": false,
    "options": []
  },
  "editable": false,
  "type": "Number",
  "name": "Desktop_Debug_Var1",
  "label": "Desktop Debug Light- Var1",
  "category": "selfruntime",
  "tags": [],
  "groupNames": [
    "gDevices",
    "gRoom_Office"
  ]
}

http://openhabianpi:8080/rest/items/Desktop_Debug_Var1/state
10.0

As mentioned the variable received at the node never updates also if we use a postUpdate in openHab it will continue to receive 0 until we issue a sendCommand at which time it will update until the next postUpdate or server reboot.

@titvs I have tested a repeater and it is still working ok after 48 hours using the CE timing modified code.

@yveaux The comment above the section indicates that TX starts after 10us, and setting CE high also enables PA+LNA mode - so I wonder why would we be trying to set it low after 10us - seems like a conflicting set of statements. Then the statement datasheet: Pulse CE at least 10us - it is confusing - Does this mean for at least 10us or after 10us and should the pulse be a set of LOW then HIGH > 10us. If I read these statements without the datasheet I would be holding it UP for at least 10us then pulse it quickly LOW/HIGH until the status updates as we need to be high to enable the PA+LNA mode. Anyway I am only looking at a very small part of the code and reading peoples comments. I would need more time to cross check the datasheet. But the removal of the 10us set it LOW is still working.

@titvs my testing seems to show that this updated version from @tekka does resolve the problem. I have added some questions about the release details etc in the post https://forum.mysensors.org/topic/9642/nrf24-transmission-of-data-works-fine-but-constant-nack-s-produced/12

@tekka I think you have solved it - I had a look at the code changes you made removing the 10ms pulse and wonder how it could be but without reading the rest of the code and understanding the specs of the card I am only guessing. So can this version of the code still work well with the regular nrf24 modules or will this pulse adjustment have a different impact on them? At present i have only loaded this on the 2 nodes I have mentioned. Will this modification be released as a point release update to the community as something like 2.3.1 or how will this be migrated to a stable release?

Great work by the way and thanks for fixing it.

@tekka Loaded onto my MEGA based Ethernet gateway connected to openHab using a E01-ML01DP5 with 9db antenna - this previously lasted less than 6 hours. Will advise as testing goes ahead. I do not send much with this unit more receive but have some test nodes I will code to toggle back and forth - I am unable to add my signed nodes to this as yet!

I will also grab my MEGA based repeater on a different network and see what happens this is a nrf24l01+ with pa + lna.

@tekka have downloaded and will look at this and report shortly. Yes most of my Gateway & Repeater nodes are nrf24l01+ with pa + lna but I have also been using and seen the problem with E01-ML01DP5 but I think this is the same underlying technology.

@rzylius thanks for that testing - it follows almost exactly the same problems I have seen since the release of 2.3.0 and is the reason I do not use 2.3.0 anymore and have reverted my entire network to 2.2.0. Sorry @mfalkvidd this is another example of the same 2.3.0 problems, I feel I am looking like a problem to the community but I did extensive testing on 2.3.0 - made posts in the release page - received nothing in reply and it seems the errors are continuing. The above logs are very similar in aspect to the testing I did so not sure what other logs you may need but I am happy to try to help if there is something I can do, but it is hard to diagnose anything when the radio network just starts NACK'ing and then eventually the node stops working?