What is slow here?

I have build a controller for my garage door using an ESP8266 for wifi connection, a relay that replaces a push button for the motor control and an ultrasonic distance sensor to find out the state of the garage door so I can have dedicated open/close commands. It has been working stable and well for a couple of weeks now, but what bothers me are quite some delays in the response.
Can anybody see what - for example - causes a delay of nearly a second until the status command returns the distance read via telnet? Or is it just the ESP8266 that isn't very fast?

#include <SoftwareSerial.h>
SoftwareSerial softSerial(10, 11); // RX, TX

#define SSID "MYSSID"
#define PASS "MYPASSWD"

#define WIFI_Serial Serial
#define Debug_Serial softSerial   
#define DEBUG true

String inString = "";
String message = "";

const int trigPin = 2;
const int echoPin = 4;
const int relayPin = 6;

long sensorReadTime = 0;
const long sensorReadInterval = 2000;
long gateDistance = 0;

void setup()
{
  WIFI_Serial.begin(9600);
  WIFI_Serial.setTimeout(5000);

  Debug_Serial.begin(9600);

  pinMode(relayPin, OUTPUT);
  digitalWrite(relayPin,HIGH);

  for(int i=0;i<10;i++)
  {
    delay(1000);
    Debug_Serial.println(i);
  }

  Debug_Serial.println("Starting up");
  WIFI_Serial.println("AT+RST");
  delay(5000);
  while(WIFI_Serial.available())
  {
    WIFI_Serial.read();
  }
  WIFI_Serial.println("AT+CWMODE=1");
  delay(1000);
  if(checkForOK())
  {
    Debug_Serial.println("Module is ready");
  }
  else
  {
    Debug_Serial.println("Module has no response.");
    while(1);
  }
  //connect to the wifi
  boolean connected=false;
  for(int i=0;i<10;i++)
  {
    if(connectWiFi())
    {
      connected = true;
      break;
    }
  }
  if (!connected){
    while(1);
  }

  //print the ip addr
  WIFI_Serial.println("AT+CIFSR");
  delay(1000);
  Debug_Serial.println("ip address:");
  while (WIFI_Serial.available())
    Debug_Serial.write(WIFI_Serial.read());

  //set multiple connection mode
  WIFI_Serial.println("AT+CIPMUX=1");
  delay(1000);
  Debug_Serial.println("multiple connection mode:");
  while (WIFI_Serial.available())
    Debug_Serial.write(WIFI_Serial.read());

  //set server mode
  WIFI_Serial.println("AT+CIPSERVER=1,23");
  delay(1000);
  Debug_Serial.println("server mode:");
  while (WIFI_Serial.available())
    Debug_Serial.write(WIFI_Serial.read());
}

void loop()
{
  if(millis()>(sensorReadTime+sensorReadInterval))
  {
    gateDistance = getGateDistance();
    Debug_Serial.print("Distance: ");
    Debug_Serial.println(gateDistance);
    sensorReadTime=millis();
  }

  if(WIFI_Serial.available())
  {
    if(WIFI_Serial.find("+IPD,"))
    {
      delay(100);
      Debug_Serial.println("Connection");
      
      int connectionId = WIFI_Serial.read()-48; // subtract 48 because the read() function returns 
                            // the ASCII decimal value and 0 (the first decimal number) starts at 48
      int length = 0;
      WIFI_Serial.read(); //Komma

      while (WIFI_Serial.available() > 0) 
      {
        int inChar = WIFI_Serial.read();
        if (isDigit(inChar)) 
        {
          inString += (char)inChar;
        }
        if (inChar == ':') 
        {
          length = inString.toInt();
          inString = "";
          break;
        }
      }
      
      for(int i = 0;i<length-2;i++)
      {
        int inChar = WIFI_Serial.read();
        inString += (char)inChar;
      }
      WIFI_Serial.read();
      WIFI_Serial.read();//Line ending
      Debug_Serial.println(inString);
      
      
      if (inString == "status")
      {
        String distance = String(gateDistance);
        
        String cipSend = "AT+CIPSEND=";
        cipSend += connectionId;
        cipSend += ",";
        cipSend +=distance.length();
        cipSend +="\r\n";
        
        sendData(cipSend,1000,DEBUG);
        sendData(distance+"\r\n",1000,DEBUG);
      }
      else if (inString == "close")
      {
        if (gateDistance<15)
        {
          digitalWrite(relayPin,LOW);
          delay(1000);
          digitalWrite(relayPin,HIGH);
          
          message="OK";
        }
        else
        {
          message="ISCLOSED";
        }
        
        String cipSend = "AT+CIPSEND=";
        cipSend += connectionId;
        cipSend += ",";
        cipSend +=message.length();
        cipSend +="\r\n";
        
        sendData(cipSend,1000,DEBUG);
        sendData(message+"\r\n",1000,DEBUG);
      }
      else if (inString == "open")
      {
        if (gateDistance>40)
        {
          digitalWrite(relayPin,LOW);
          delay(1000);
          digitalWrite(relayPin,HIGH);
          message="OK";
        }
        else
        {
          message="ISOPEN";
        }        
        String cipSend = "AT+CIPSEND=";
        cipSend += connectionId;
        cipSend += ",";
        cipSend +=message.length();
        cipSend +="\r\n";
        
        sendData(cipSend,1000,DEBUG);
        sendData(message+"\r\n",1000,DEBUG);
      }
      String closeCommand = "AT+CIPCLOSE="; 
      closeCommand+=connectionId; // append connection id
      closeCommand+="\r\n";
        
      sendData(closeCommand,3000,DEBUG); 
      inString="";
    }
  }
}

String sendData(String command, const int timeout, boolean debug)
{
    String response = "";
    
    WIFI_Serial.print(command); // send the read character to the esp8266
    
    long int time = millis();
    
    while( (time+timeout) > millis())
    {
      while(WIFI_Serial.available())
      {
        
        // The esp has data so display its output to the serial window 
        char c = WIFI_Serial.read(); // read the next character.
        response+=c;
      }  
    }
    
    if(debug)
    {
      Debug_Serial.print(response);
    }
    
    return response;
}

boolean connectWiFi()
{
  
  String cmd="AT+CWJAP=\"";
  cmd+=SSID;
  cmd+="\",\"";
  cmd+=PASS;
  cmd+="\"";
  Debug_Serial.println(cmd);
  WIFI_Serial.println(cmd);
  delay(10000);  
  if(checkForOK())
  {
    Debug_Serial.println("OK, Connected to WiFi.");
    return true;
  }
  else
  {
    Debug_Serial.println("Can not connect to the WiFi.");
    return false;
  }
}

long getGateDistance()
{
  // establish variables for duration of the ping, 
  // and the distance result in inches and centimeters:
  long duration;
 
  // The sensor is triggered by a HIGH pulse of 10 or more microseconds.
  // Give a short LOW pulse beforehand to ensure a clean HIGH pulse:
  pinMode(trigPin, OUTPUT);
  digitalWrite(trigPin, LOW);
  delayMicroseconds(2);
  digitalWrite(trigPin, HIGH);
  delayMicroseconds(10);
  digitalWrite(trigPin, LOW);
 
  // Read the signal from the sensor: a HIGH pulse whose
  // duration is the time (in microseconds) from the sending
  // of the ping to the reception of its echo off of an object.
  pinMode(echoPin, INPUT);
  duration = pulseIn(echoPin, HIGH);
 
  // convert the time into a distance
  return microsecondsToCentimeters(duration);
}

boolean checkForOK()
{
  char inChar;
  boolean oLast=false;
  boolean returnV = false;
  
  while (WIFI_Serial.available())
  {
    inChar=WIFI_Serial.read();
    Debug_Serial.print(inChar);
    if(oLast && inChar == 'K')
      returnV=true;
    else if (inChar == 'O')
      oLast = true;
    else
      oLast = false;
  }
  Debug_Serial.println();
  return returnV;
}

long microsecondsToInches(long microseconds)
{
  // According to Parallax's datasheet for the PING))), there are
  // 73.746 microseconds per inch (i.e. sound travels at 1130 feet per
  // second).  This gives the distance travelled by the ping, outbound
  // and return, so we divide by 2 to get the distance of the obstacle.
  // See: http://www.parallax.com/dl/docs/prod/acc/28015-PING-v1.3.pdf
  return microseconds / 74 / 2;
}
 
long microsecondsToCentimeters(long microseconds)
{
  // The speed of sound is 340 m/s or 29 microseconds per centimeter.
  // The ping travels out and back, so to find the distance of the
  // object we take half of the distance travelled.
  return microseconds / 29 / 2;
}

I don't understand the logic of your code - perhaps you can provide a description of how it is supposed to work?

It may be that your code should have two states - one in which it is looking for a signal and another for when it has made a connection and is expected to function quickly without the need to establish the connection.

These lines would seem to prevent loop() from repeating frequently. The FIND function blocks until some timeout is reached and the delay(100) on its own limits loop() to repeating 10 times per second. Ideally loop() should repeat hundreds or thousands of times per second.

if(WIFI_Serial.find("+IPD,"))
    {
      delay(100);

Have a look at the examples in serial input basics which don't block the Arduino.

...R

You are sending the data in two parts and there is a 1000 millisecond timeout on the first part. The sendData() function always waits for the full timeout, never even trying to determine if the response completes before the timeout.

Note: When millis() wraps every 49+ days there is a chance that your timeout will run long... by about 49 days. You should use (millis() - time < timeout) rather than (time + timeout > millis()).

    if (inString == "status")
      {
        sendData(cipSend,1000,DEBUG);
        sendData(distance+"\r\n",1000,DEBUG);
      }
String sendData(String command, const int timeout, boolean debug)
{
    WIFI_Serial.print(command); // send the read character to the esp8266
    long int time = millis();
    while( (time+timeout) > millis())
    {
     }
}
  for(int i=0;i<10;i++)
  {
    delay(1000);
    Debug_Serial.println(i);
  }

What possible value is this code?

 if(WIFI_Serial.available())
  {
    if(WIFI_Serial.find("+IPD,"))
    {
      delay(100);
      Debug_Serial.println("Connection");
      
      int connectionId = WIFI_Serial.read()-48;

In addition to what Robin says, find() returns when the string it is looking for is found. What makes you think that there is ANY more serial data to read? How often are you assigning -49 to connectionId?

     int length = 0;
      WIFI_Serial.read(); //Komma

A completely unwarranted assumption.

And that is where I stopped reading.

ElCaron:
Can anybody see what - for example - causes a delay of nearly a second until the status command returns the distance read via telnet? Or is it just the ESP8266 that isn't very fast?

I don't fully understand your programming logic, which looks like a whole pile of mess to me, but if you are using "blocking functions" that run with a timeout until they are finished, your program is blocked each time if the timeout occurs.

Example:

    if(WIFI_Serial.find("+IPD,"))
    {
      delay(100);
...

The Serial.find() command means with the default timeout configuration:

  • Block the program execution until
  • either the string "+IPD," is received
  • or one second has passed without receiving the string

So I suppose: In many cases this will cause a one second blocking in program execution.

And "delay(100)" means "block program execution for another 0.1 seconds".

So if your main loop consists of code with the meaning "block program execution for one second", followed by code with the meaning "block program execution for another 0.1 seconds", this is a program execution blocking for a total of 1.1 seconds.

No matter what speed the ESP8266 provides.

@Robin

The loop part of the code checks the distance to the garage door every 2 seconds and saves the result (ll. 94-100). It also waits for a connection from the ESP8266 (WIFI_Serial.available()). Since it is the only thing that I expect from the ESP, I explicitly parse for the form +IPD,,:. Then, depending on , I send the measured distance to the gate as a status, or open the gate if closed, or close the gate if open. Since closing and opening is the same relay, I need the distance to determine if the gate is really closed, before I open it.

@johnwasser
That is most probably the problem. I overlooked that. Thanks! (Also for the small fix)

@PaulS
The use of the code you quoted is to to give me time to set up the serial debug console during startup and to see how far it has proceed. You might have noticed that is in the setup function.

In addition to what Robin says, find() returns when the string it is looking for is found.

Yes, that is totally what it is expected to do.

What makes you think that there is ANY more serial data to read?

The datasheet of the ESP8266. Of course there may be more robust solutions, but this is my garage door not a commercial product. I don't see a reason to spend much time and energy to catch every possible error when this solution hasn't given a problem over weeks.

How often are you assigning -49 to connectionId?

Never by now, as far as I noticed.

And that is where I stopped reading.

We live in free countries.

@jurs
The only stuff that I expect to come at that position of the code from the ESP is stuff that starts with "+IPD,".
If if there occationally comes something else, everything that is slow happens inside that if-statement, so the find shouldn't cause that problem - it might only block the device.

ElCaron:
The loop part of the code checks the distance to the garage door every 2 seconds and saves the result (ll. 94-100). It also waits for a connection from the ESP8266 (WIFI_Serial.available()). Since it is the only thing that I expect from the ESP, I explicitly parse for the form +IPD,,:. Then, depending on , I send the measured distance to the gate as a status, or open the gate if closed, or close the gate if open. Since closing and opening is the same relay, I need the distance to determine if the gate is really closed, before I open it.

This description is at a rather higher level than I was hoping for. What I would like to see is "walk-through" of the code.

And you have not responded to any of the other suggestions/comments I made in Reply #1

...R

Hi Robin2, below is a version of the setup and loop functions with a few more comments. I hope that clears it up. On the other hand, johnwasser's answer most certainly cleared where the obvious problem is and I think I should redesign more than that. So don't put too much effort in that anymore. I think your link will greatly help, thanks.

Regarding the other comments: The find/delay should not block the loop, since it is inside a "if(WIFI_Serial.available())". I only expect "+IPD" coming from there, so it should quickly find it and go on. In the worst case, occasionally something else comes and blocks the code for a second, but that would only cause a slightly older distance scan. In the really worst case, something else comes, then I connect, find timeouts after "+IP" and I loose a connection attempt. But "something else comes" never or very seldom happens and my connection attempts are very sparse, I consider this problem more a theoretical one.

#include <SoftwareSerial.h>
SoftwareSerial softSerial(10, 11); // RX, TX

#define SSID "MYSSID"
#define PASS "MYPASSWD"

#define WIFI_Serial Serial
#define Debug_Serial softSerial   
#define DEBUG true

String inString = "";
String message = "";

const int trigPin = 2;
const int echoPin = 4;
const int relayPin = 6;

long sensorReadTime = 0;
const long sensorReadInterval = 2000;
long gateDistance = 0;

void setup()
{
  WIFI_Serial.begin(9600);
  WIFI_Serial.setTimeout(5000);

  Debug_Serial.begin(9600);

  pinMode(relayPin, OUTPUT);
  digitalWrite(relayPin,HIGH);

  // Wait 10 seconds for my to set up the debug console, output counter
  for(int i=0;i<10;i++)
  {
    delay(1000);
    Debug_Serial.println(i);
  }

  // Start the ESP. The responses is relatively long with delays and I don't care about them, so I just wait some time and then through it away
  Debug_Serial.println("Starting up");
  WIFI_Serial.println("AT+RST");
  delay(5000);
  while(WIFI_Serial.available())
  {
    WIFI_Serial.read();
  }

  // Set ESP mode. I am looking for ok, but I don't want to loose the output in case of problems, so checkForOK() replaces find()
  WIFI_Serial.println("AT+CWMODE=1");
  delay(1000);
  if(checkForOK())
  {
    Debug_Serial.println("Module is ready");
  }
  else
  {
    Debug_Serial.println("Module has no response.");
    while(1);
  }

  //connect to the wifi
  boolean connected=false;
  for(int i=0;i<10;i++)
  {
    if(connectWiFi())
    {
      connected = true;
      break;
    }
  }
  if (!connected){
    while(1);
  }

  //print the ip addr
  WIFI_Serial.println("AT+CIFSR");
  delay(1000);
  Debug_Serial.println("ip address:");
  while (WIFI_Serial.available())
    Debug_Serial.write(WIFI_Serial.read());

  //set multiple connection mode
  WIFI_Serial.println("AT+CIPMUX=1");
  delay(1000);
  Debug_Serial.println("multiple connection mode:");
  while (WIFI_Serial.available())
    Debug_Serial.write(WIFI_Serial.read());

  //set server mode
  WIFI_Serial.println("AT+CIPSERVER=1,23");
  delay(1000);
  Debug_Serial.println("server mode:");
  while (WIFI_Serial.available())
    Debug_Serial.write(WIFI_Serial.read());
}

void loop()
{
  // Check distance to garage door and save it.
  if((millis()-sensorReadTime)>sensorReadInterval)
  {
    gateDistance = getGateDistance();
    Debug_Serial.print("Distance: ");
    Debug_Serial.println(gateDistance);
    sensorReadTime=millis();
  }

  if(WIFI_Serial.available()) //Something comes from the ESP
  {
    if(WIFI_Serial.find("+IPD,")) //I assume the form "+IPD,<id>,<len>:<data>"
    {
      delay(100); // Wait to not outrun the incomming serial connection
      Debug_Serial.println("Connection");
      
      int connectionId = WIFI_Serial.read()-48; // subtract 48 because the read() function returns 
                            // the ASCII decimal value and 0 (the first decimal number) starts at 48
      int length = 0;
      WIFI_Serial.read(); //Komma
      
      //Read the <len>
      while (WIFI_Serial.available() > 0) 
      {
        int inChar = WIFI_Serial.read();
        if (isDigit(inChar)) 
        {
          inString += (char)inChar;
        }
        if (inChar == ':') 
        {
          length = inString.toInt();
          inString = "";
          break;
        }
      }
      
      // Read <data> with length <len>
      for(int i = 0;i<length-2;i++)
      {
        int inChar = WIFI_Serial.read();
        inString += (char)inChar;
      }
      WIFI_Serial.read();
      WIFI_Serial.read();//Line ending
      Debug_Serial.println(inString);
      
      // data can correspond to 3 strings, "status", "open", "close". decide what to do based on that
      if (inString == "status") // print distance from sensor
      {
        String distance = String(gateDistance);
        
        String cipSend = "AT+CIPSEND=";
        cipSend += connectionId;
        cipSend += ",";
        cipSend +=distance.length();
        cipSend +="\r\n";
        
        sendData(cipSend,1000,DEBUG);
        sendData(distance+"\r\n",1000,DEBUG);
      }
      else if (inString == "close") // close ...
      {
        if (gateDistance<15) // ... if gate open
        {
          digitalWrite(relayPin,LOW);
          delay(1000);
          digitalWrite(relayPin,HIGH);
          
          message="OK";
        }
        else
        {
          message="ISCLOSED";
        }
        
        String cipSend = "AT+CIPSEND=";
        cipSend += connectionId;
        cipSend += ",";
        cipSend +=message.length();
        cipSend +="\r\n";
        
        sendData(cipSend,1000,DEBUG);
        sendData(message+"\r\n",1000,DEBUG);
      }
      else if (inString == "open") // open ...
      {
        if (gateDistance>40) // ... if gate closed
        {
          digitalWrite(relayPin,LOW);
          delay(1000);
          digitalWrite(relayPin,HIGH);
          message="OK";
        }
        else
        {
          message="ISOPEN";
        }        
        String cipSend = "AT+CIPSEND=";
        cipSend += connectionId;
        cipSend += ",";
        cipSend +=message.length();
        cipSend +="\r\n";
        
        sendData(cipSend,1000,DEBUG);
        sendData(message+"\r\n",1000,DEBUG);
      }
      String closeCommand = "AT+CIPCLOSE="; 
      closeCommand+=connectionId; // append connection id
      closeCommand+="\r\n";
        
      sendData(closeCommand,3000,DEBUG); 
      inString="";
    }
  }
}

ElCaron:
Hi Robin2, below is a version of the setup and loop functions with a few more comments.

Thanks. That is a big help.

I notice that your data has a line-ending character (which you are ignoring). I think it would be much simpler just to read all the data up to the line-end character and then analyse it. The second example in serial input basics works like that.

An important aspect of the design of the examples in serial input basics is that they don't block the Arduino.

I think you need to adopt a similar approach for your sendData() function so that it does not block the Arduino.

Also, your sendData() function seems to need to receive data. It would make sense to have only one receive data function and use it from sendData() as well as elsewhere.

You should also be aware that using Strings (capital S) on the Arduino can cause problems because of the limited amount of SRAM. Better to use strings (small s).

...R

Hi Robin2, thanks for the suggestions. I am currently rebuilding most of the code and read your thread about serial input. I posted a question at the end of that thread, it would be great if you could have a look.

The sendData stuff is indeed pretty stupid, I took it from another example code without looking into it hard enough.

ElCaron:
it would be great if you could have a look.

I noticed that you already have an answer.

...R

Sorry, to perhaps unnecessarily bump it up, but the other ESP8266 question reminded me that others might be interested in the rewritten code.

It is non-blocking in most cases and only blocks when I wouldn't know what to do with other input at that time anyway.

ElCaron:
might be interested in the rewritten code.

It is good of you to share your code.
But why not post it here in the Forum where it is easier to access ?

...R