ESP8266 WiFi gateway port for MySensors

[Yveaux]

@tjay4x4 try development version of MySensors. This thread discussions a similar issue:
http://forum.mysensors.org/topic/2118/esp8266-wifi-gateway-issue/2

[Yveaux]

@tjay4x4 Just crossed my reply! Great it's working now!

[robosensor]

Yesterday I switched gateway hardware from serial gateway based on arduino pro mini 3.3V and nrf24l01+ (connected directly to uart port of my mikrotik router) to esp8266 nodemcu and nrf24l01+ (exactly as at this page: http://www.mysensors.org/build/esp8266_gateway, using GatewayESP8266 sketch from 1.6 branch, revision https://github.com/mysensors/Arduino/tree/1035f84a431a8f591d31100c3e73e99a8245e345).

I have 4 nodes with ~27 sensors total, half of sensors sending data every 10 seconds, another sensors send data only if environment changed.

After switching to esp8266 my gateway started loosing packets (messages) from my sensor nodes:

Left side of graphs is esp8266, right side is old pro mini serial gateway, sensors sending data every 10 seconds. Distance between gateways is about 5-10 centimeters. Both nrf24l01+ boards oriented in the same direction.

nrf24l01+ board isn't changed at all (I'm using old board from pro mini serial gateway).

Also, I have tried different nrf24l01+ boards (different PCBs and different chip revisions, but seems like all of them are fake china chips). I have tried soldering 220 uF electrolytic and 0.1 uF ceramic capacitors directly to nrf24l01+ power pins. But nothing changed. Esp8266 gateway is losing messages.

Switching back to pro mini serial gateway is completely solves issue (as shown in graph above).

What else can I try to fix this? Could it be interference between wifi chip and nrf24? Or, maybe, this is software problem? Maybe non-interrupt driven polling of nrf24l01 causes loosing messages coming too often?

[hek]

@robosensor

Interesting graph... But I have no immediate answer to you.

[robosensor]

@hek graphs are drawn by Zabbix. My own Perl script connects directly to gateway, reads sensor data and sends this data directly to Zabbix.

Also, I have tried to write raw data from gateway directly to file and execute "tail -f logfile.txt | grep sensor-specific-id". With old pro mini gateway data from sensor comes every 10 seconds. From esp8266 gateway sensor data comes very irregular.

Also, every send() call in all my nodes followed by wait(25) call to reduce possible power issues and interference issues.

UPDATE: I have recompiled esp8266-gateway sketch with debugging enabled, but I get the same results with loosing messages then I connecting directly to uart port of esp8266 uart-usb converter.

[Yveaux]

@robosensor What strikes me is the fact that most of the time not all sensor values seem to disappear at the same time. A failing WiFi connection would be the most likely cause when all dis/reappear at the same time (like at 13:44 and 13:22).
However, most of the time at least one sensor seems to report its values correctly. IMO This rules out the radio.
Is there anything interesting in the serial logs?

[robosensor]

@Yveaux thank you for your reply. It is not failing wifi connection, as the same problem exists then I using serial connection to esp8266 (via on-board usb-uart converter on nodemcu board).

Nothing interesting in the serial logs (with debug mode enabled), just random absence of sensor data. Seems like I should connect sensor node to collect debug logs from node side.

Also speed is changed - much faster CPU (80 MHz vs 8 MHz) and much faster connection (wifi vs uart 9600 bps). Maybe this affects.

[robosensor]

Seems like problem with loosing messages is gateway firmware related.

Then I connect two controllers (my own perl script and MYSController 0.1.2.282) to esp8266 gateway (#define MY_GATEWAY_MAX_CLIENTS 2), both controllers receiving exactly the same data from gateway, but messages lost even more.

1 on graphs = one controller connected
2 on graphs = two controllers connected.

I'm not familiar with esp8266 network programming, but could it be that firmware looses incoming packets from nrf24l01+ due to blocking call to wifi-related network functions? Seems like during sending data to wifi network firmware does not have time to pick up all incoming packets from nrf24l01+ chip.

[robosensor]

I think I found problem. As I said before, seems like WiFi's clients[i].write() call blocks thread for a very long time.

I added logging of write() time:

		// Send message to connected clients
		#if defined(MY_GATEWAY_ESP8266)
			unsigned long start_time = hwMillis();
			for (uint8_t i = 0; i < ARRAY_SIZE(clients); i++)
			{
				if (clients[i] && clients[i].connected())
				{
					clients[i].write((uint8_t*)_ethernetMsg, strlen(_ethernetMsg));
				}
			}
			debug(PSTR("WiFi transaction time: %u ms\n"), hwMillis() - start_time);
		#else
			_ethernetServer.write(_ethernetMsg);
		#endif

And got following results:
For Perl script from FreeBSD server in another country (ping to server is about 55 milliseconds):

0;0;3;0;9;WiFi transaction time: 141 ms
0;0;3;0;9;read: 2-2-0 s=1,c=1,t=23,pt=2,l=2,sg=0:98
0;0;3;0;9;WiFi transaction time: 141 ms
0;0;3;0;9;read: 2-2-0 s=6,c=1,t=43,pt=3,l=2,sg=0:2
0;0;3;0;9;WiFi transaction time: 140 ms
0;0;3;0;9;read: 1-1-0 s=105,c=1,t=0,pt=7,l=5,sg=0:27.5000
0;0;3;0;9;WiFi transaction time: 136 ms
0;0;3;0;9;read: 1-1-0 s=106,c=1,t=0,pt=7,l=5,sg=0:52.8750
0;0;3;0;9;WiFi transaction time: 140 ms
0;0;3;0;9;read: 1-1-0 s=107,c=1,t=0,pt=7,l=5,sg=0:45.9375
0;0;3;0;9;WiFi transaction time: 142 ms
0;0;3;0;9;read: 1-1-0 s=108,c=1,t=0,pt=7,l=5,sg=0:34.4375
0;0;3;0;9;WiFi transaction time: 137 ms
0;0;3;0;9;read: 1-1-0 s=1,c=1,t=16,pt=0,l=1,sg=0:0
0;0;3;0;9;WiFi transaction time: 143 ms

Connection from LAN (windows telnet client):

0;0;3;0;9;read: 3-3-0 s=1,c=1,t=23,pt=2,l=2,sg=0:61
0;0;3;0;9;WiFi transaction time: 209 ms
0;0;3;0;9;read: 4-4-0 s=1,c=1,t=24,pt=2,l=2,sg=0:152
0;0;3;0;9;WiFi transaction time: 201 ms
0;0;3;0;9;read: 4-4-0 s=2,c=1,t=24,pt=2,l=2,sg=0:43
0;0;3;0;9;WiFi transaction time: 212 ms
0;0;3;0;9;read: 4-4-0 s=3,c=1,t=24,pt=2,l=2,sg=0:129
0;0;3;0;9;WiFi transaction time: 209 ms
0;0;3;0;9;read: 4-4-0 s=4,c=1,t=24,pt=2,l=2,sg=0:147
0;0;3;0;9;WiFi transaction time: 208 ms
0;0;3;0;9;read: 2-2-0 s=102,c=1,t=0,pt=7,l=5,sg=0:4.2500
0;0;3;0;9;WiFi transaction time: 221 ms
0;0;3;0;9;read: 2-2-0 s=103,c=1,t=0,pt=7,l=5,sg=0:27.4375
0;0;3;0;9;WiFi transaction time: 208 ms
0;0;3;0;9;read: 2-2-0 s=104,c=1,t=0,pt=7,l=5,sg=0:23.3750
0;0;3;0;9;WiFi transaction time: 210 ms
0;0;3;0;9;read: 2-2-0 s=3,c=1,t=1,pt=7,l=5,sg=0:99.9
0;0;3;0;9;WiFi transaction time: 208 ms

Seems like many packets coming to NRF24L01+ in this time interval (140-200 milliseconds) and this causes NRF buffer overflow and packet loss.

[hek]

Damn, 200 msec is a pretty long time.

[Yveaux]

@hek Yeah, but is this significantly longer than for a wired connection?
Only real solution would be to switch to interrupt based message handling for the MySensors network (hopefully the ESP stack can handle this...)
@robosensor Are these long delays (only) caused by the fact that this is a long distance connection?
How is your mileage for a server on e.g. the same lan?

[Fabien]

Exactly same problem here with RFM69W Radio. With 2 clients, i loose more packets. Both controller and ESP are on the same LAN. No probelm with Serial Gateway on Jeelink v3.

[robosensor]

@Yveaux seems like delays caused by low-level network/tcp code or settings of receiving side (maybe something as TCP ACK packet delays or Nagle algorithm or something like this).

ESP8266 connected directly to Mikrotik RB2011 router.

Then I connect from external server (ping to server is about 55 milliseconds, FreeBSD 9.3, Perl), delays about 140 milliseconds.
Then I connect from windows-based computer, connected directly to router, delays about 200 milliseconds (both windows telnet and PuTTy).
For 2 parallel above connections delays about 350 milliseconds.

Then I connect from router's internal telnet client, delays about 1-2 milliseconds
Then I connect from android-based phone (phone connected to router via wifi, using ConnectBot software), delays vary from 3-5 milliseconds (mostly) to 100-150 milliseconds (less frequently).

Seems like interrupts for nrf24 is the only solution. Seems like esp8266 gateway with such delays is completely unusable with high packet rates. With ~150 milliseconds delays no more than 6 messages/second packet rate allowed.

Just to reference: I'm using Arduino 1.6.5 with esp8266 libraries version 2.0.0 installed.

[Yveaux]

@robosensor @Fabien Please understand that this issue is not related to ESP8266. I expect delays to be nearly identical when using the Ethernet gateway (wired ethernet) and ATMega microcontroller. Of course the serial gateway will not suffer from these delays as it doesn't use ethernet as transport medium -- it is a direct connection.
Switching to interrupt-based message handling for the MySensorts stack is not a simple task. It will require locking and buffering, and footprint of the library (especially RAM) will increase.
Furthermore I don't know how the ESP's network stack handles interrupts during ethernet processing. Worst case it will just block interrupts or run from a higher-priority interrupt than the nRF and all efforts of making the MySensors library interrupt based will be in vain.
I personally would try to reduce the latency in your server connection by choosing a server nearby or by buffering your traffic by a server in your LAN. MQTT for example can easily be buffered by a local broker which then uses the slow connection to sync with another server.
Another option is switching to a serial gateway, but again you need a local server inbetween.
A simple Raspberry Pi or so could act as a server for these scenarios.

Another option would be to implement a retry mechanism on your sensors. If the gateway does not confirm reception of your message, then resend it.

[robosensor]

@Yveaux I completely agree with you. Rewriting gateway code to support interrupts is not very easy task and it is not clear what problems you will encounter. Furthermore, rewriting will not solve the problem of delays, this only can solve packet loss problem.

Just tried to connect from RPi 2 (connected using WiFi directly to router), average delay is 2-5 milliseconds, sometimes 5-10 ms. Seems like this is good temporary solution.

[D_dude]

@Yveaux said:

@D_dude flush the serial output after each print.
The ESP will output the serial data in the background while your programm continues and then it crashes.

Finally was able to get everything working.
Ordered a fresh nRF from Itead and started from scratch. everything worked fine first time. seems like the nRF from ebay was causing issues.

[robosensor]

Just tried old version of esp8266 libraries (1.6.5-947-g39819f0 instead of 2.0.0) with old version of esp8266 gateway (master branch, commit 9ef2604c81d2fea5d646a9a194f312192833a79b) and got exactly the same results.

WiFi write() time is about 150-200 milliseconds for remote server in another country, 200-210 milliseconds for windows7-based computer in local area network and 0-4 milliseconds for Raspberry Pi 2 in local area network.

To show transaction times just replace original output function in Esp8266Gateway.ino with following code:

void output(const char *fmt, ... )
{
  char serialBuffer[MAX_SEND_LENGTH];
  va_list args;
  va_start (args, fmt );
  vsnprintf_P(serialBuffer, MAX_SEND_LENGTH, fmt, args);
  va_end (args);
  Serial.print(serialBuffer);

  unsigned long start_time = millis();
  
  for (uint8_t i = 0; i < ARRAY_SIZE(clients); i++)
  {
    if (clients[i] && clients[i].connected())
    {
//       Serial.print("Client "); Serial.print(i); Serial.println(" write");
       clients[i].write((uint8_t*)serialBuffer, strlen(serialBuffer));
    }
  }
  
  start_time = millis() - start_time;
  Serial.print("WiFi transaction time: "); Serial.print(start_time); Serial.println("");
}

Also disconnection of client during clients[i].write() call causes reboot by watchdog:

 ets Jan  8 2013,rst cause:4, boot mode:(3,7)

wdt reset
load 0x4010f000, len 1264, room 16 
tail 0
chksum 0x42
csum 0x42
~ld

[Yveaux]

@robosensor said:

WiFi write() time is about 150-200 milliseconds for remote server in another country, 200-210 milliseconds for windows7-based computer in local area network and 0-4 milliseconds for Raspberry Pi 2 in local area network.

So another confirmation of what we knew already.

Do you know how many nRF messages are actually sent during this wifi write call?
The nRF has a rx buffer for 3 messages -- not sure if MySensors uses all 3 of them.

Also disconnection of client during clients[i].write() call causes reboot by watchdog

I guess this is ESP core related. Is this fixed in code 2.0.0?

[robosensor]

@Yveaux said:

So another confirmation of what we knew already.

Yes. It seems that I now understand what is happening. WiFiClient::write() blocks thread until TCP ACK packet received or until timeout (5 seconds). Windows sending TCP ACKs after 200ms timeout. That's why write() delayed for ~200 milliseconds for windows-based controller. More information (and link to non-blocking library) is available here: https://github.com/esp8266/Arduino/issues/922

Do you know how many nRF messages are actually sent during this wifi write call?
The nRF has a rx buffer for 3 messages -- not sure if MySensors uses all 3 of them.

Nodes sending 3-7 (sometimes more) messages with 35 ms delay between messages, so in my case 3-packet hardware buffer in nrf24 is overflowed after 105-140 milliseconds of write() call.

Also disconnection of client during clients[i].write() call causes reboot by watchdog
I guess this is ESP core related. Is this fixed in code 2.0.0?

I did not tried to check this reboots in 2.0.0, but 2.0.0 is much more stable and I never seen any reboots/resets.

[Yveaux]

@robosensor said:

2.0.0 is much more stable and I never seen any reboots/resets.

That sounds promising! I'll have to give the 2.0.0 core a try myself then.