espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
13.62k stars 7.41k forks source link

Arduino BluetoothSerial crash after streaming data for a period, especially on interrupt. #2362

Closed joshbrew closed 5 years ago

joshbrew commented 5 years ago

Hardware:

Board: LOLIN32 V1.0.0 Core Installation version: 1.0.1 IDE name: Arduino IDE Flash Frequency: 80MHz PSRAM enabled: ? Upload Speed: 921600 Computer OS: Win 10 and Android

Description:

Describe your problem here Am trying to sync a phone with a bluetooth serial stream. I've gotten the stream working in BLE but could not read the write bytes on the ESP32 correctly in the UART example when I tried writing to it. So I switched to SerialBT which is more simple for my needs, but now I'm getting periodic crashing after streaming for a few minutes, especially when trying to interrupt. Ironically it seems to happen only at slower Bluetooth update rates. I have a light sensor and an ADS1115 on the 5V pins which might be causing a power draw issue but this was no issue with BLE.

Could this also be related to the speed at which my receiver is reading bytes? I've been testing an app and it's not well optimized and can lag behind, but that doesn't explain to me why it doesn't crash at higher rates than the app can keep up with.

Sketch: (leave the backquotes for code formatting)


//Change the code below by your sketch
#include "BluetoothSerial.h"

#include <Wire.h>
#include <Adafruit_ADS1015.h>
//#include <ArduinoJson.h>

BluetoothSerial SerialBT;

int count = 0;
bool sensorEnabled = false;
bool adcEnabled = false;
bool usbSerialEnabled = false;

char received;
//char ratioBuf[6], adcBuf[6];

// HEG VARIABLES
bool DEBUG = false;
bool VIEW_ADC_VALUE = false;
bool SEND_DUMMY_VALUE = false;

// PUT IR IN 13, RED IN 12
const int IR = 13;
const int RED = 12;
const int LED = 5; // Lolin32V1.0.0 LED on Pin 5
int16_t adc0; // Resulting 16 bit integer

//Setup ADS1115
Adafruit_ADS1115 ads;

float Voltage = 0.0;
float range = 32767; // 16 bit ADC (15 bits of range minus one)
float gain = 0.256; // +/- V
float bits2mv = gain / range;

//Signal flags
bool first_led = false; // Bool to alternate LEDS
bool badSignal = false;
bool signalDetermined = false;

//Counters
int ticks0, ticks1, ticks2, ticks3, ticks4 = 0;

//Scoring variables
long redValue = 0;
long irValue = 0;
float redavg = 0;
float iravg = 0;
float ratio = 0;
float baseline = 0;

float score = 0;

float p1, p2 = 0;
float v1, v2 = 0;
float accel = 0;

float ratioAvg, adcAvg, posAvg, velAvg, accelAvg;
//float scoreAvg;

//Timing variables
unsigned long startMillis;
unsigned long currentMillis;
unsigned long ledMillis;
unsigned long BLEMillis;

//Make sure these divide without remainders for best results
const unsigned long ledRate = 50; // LED flash rate (ms)
const unsigned long sampleRate = 2; // ADC read rate (ms). ADS1115 has a max of 860sps or 1/860 * 1000 ms or 1.16ms
const unsigned long samplesPerRatio = 50; // Number of samples per LED to accumulate before making a measurement. Time = 2*samples*sampleRate
const unsigned long BTRate = 333; // Bluetooth notify rate (ms). Min rate should be 10ms, however it will crash if your device cannot read fast enough as the buffer won't flush.

void startADS() {
  // Begin ADS
  ads.begin();
  ads.setGain(GAIN_SIXTEEN);

  //ads.setGain(GAIN_TWOTHIRDS);  // 2/3x gain +/- 6.144V  1 bit = 3mV (default)
  //ads.setGain(GAIN_ONE);     // 1x gain   +/- 4.096V  1 bit = 2mV
  //ads.setGain(GAIN_TWO);     // 2x gain   +/- 2.048V  1 bit = 1mV
  //ads.setGain(GAIN_FOUR);    // 4x gain   +/- 1.024V  1 bit = 0.5mV
  //ads.setGain(GAIN_EIGHT);   // 8x gain   +/- 0.512V  1 bit = 0.25mV
  //ads.setGain(GAIN_SIXTEEN); // 16x gain  +/- 0.256V  1 bit = 0.125mV
  //Start timers
  startMillis = millis();
  ledMillis = millis();
}

void commandESP32(char received){
  if(received == 't'){
    sensorEnabled = true;
    digitalWrite(LED,LOW);
  }
  if(received == 'f'){
    sensorEnabled = false;
    digitalWrite(LED,HIGH); 
    digitalWrite(RED,LOW);
    digitalWrite(IR,LOW); 
  }
  if(received == 'u'){
    usbSerialEnabled = true;
  }
  if(received == 'b') {
    usbSerialEnabled = false;
  }
  delay(2000);
}

void setup() {
  //Serial.begin(115200);

  pinMode(IR, OUTPUT);
  pinMode(RED, OUTPUT);
  //LOLIN32 ONLY
  pinMode(LED,OUTPUT);
  digitalWrite(LED,HIGH);

  SerialBT.begin("My_HEG");
  BLEMillis = millis();
}

void core_program() {
  if(sensorEnabled == true) {
    if(adcEnabled == false) {
      startADS();
      adcEnabled = true;
    }

    currentMillis = millis();

    if(currentMillis - startMillis >= sampleRate) {

      // read the analog in value:
      adc0 = ads.readADC_SingleEnded(0);
      //Voltage = (adc0 * bits2mv);

      // print the results to the Serial Monitor:
      if (VIEW_ADC_VALUE == true) {
        //Serial.println("ADC Value: ");
        //Serial.println(adc0);
        //Serial.println("\tVoltage: "); 
        //Serial.println(Voltage,7);
      }
      if (DEBUG == false) {
        if(adc0 >= 7000) { // The gain is high but anything over 7000 is most likely not a valid signal
          //Serial.println("\nBad Read ");
          badSignal = true;

          //Temp: reset baseline on bad read
          signalDetermined = false;
          baseline = 0;

          ticks0 = 0; // Reset counter
          ticks1 = 0;
          ticks2 = 0;
          redValue = 0; // Reset values
          irValue = 0;
        }
        else {
          badSignal = false;
          if(signalDetermined == false){
            ticks0++;
            if(ticks0 > 500) { // Wait for 500 samples of good signal before getting baseline
              // IR IN 12, RED IN 13
              if((ticks1 < 500) && (ticks2 < 500)) { // Accumulate samples for baseline
                if(first_led == true) { // RED
                  redValue += adc0;
                  ticks1++;
                }
                else { // IR
                  irValue += adc0;
                  ticks2++;
                }
                //Serial.println("\nGetting Baseline. . .");
              }
              else {
                signalDetermined = true;
                redavg = redValue / ticks1;
                iravg = irValue / ticks2;

                baseline = redavg / iravg; // Set baseline ratio
                ticks0 = 0; // Reset counters
                ticks1 = 0;
                ticks2 = 0;
                redValue = 0; // Reset values
                irValue = 0;

                //Uncomment this
                //Serial.println("\tBaseline R: ");
                //Serial.print(baseline,4);
              }
            }
          }
          else {
            ticks0++;
            if(first_led == true) { // RED
              redValue += adc0;
              ticks1++;
            }
            else { // IR
              irValue += adc0;
              ticks2++;
            }
            if((ticks2 > samplesPerRatio) && (ticks1 > samplesPerRatio)) { // Accumulate 50 samples per LED before taking reading
              redavg = redValue / ticks1; // Divide value by number of samples accumulated
              iravg = irValue / ticks2;
              ratio = redavg / iravg; // Get ratio
              ratioAvg += ratio;

              p1 = p2;
              p2 = ratio - baseline; // Position
              posAvg += p2;

              //v1 = v2;
              //v2 = (p2 - p1) * ticks0 * 0.001; // Velocity in ms
              //velAvg += v2;

              //accel = (v2 - v1) * ticks0 * 0.001; // Acceleration in ms^2
              //accelAvg += accel;

              //score += ratio-baseline; // Simple scoring method
              //scoreAvg += score;

              /*
              Serial.print("\tBaseline R: ");
              Serial.print(baseline,4);
              //Serial.print("\tRed: ");
              //Serial.print(redavg);
              //Serial.print("\tIR: ");
              //Serial.print(iravg);
              Serial.print("\tCurrent R: ");
              Serial.print(ratio,4);
              Serial.print("\trPosition: ");
              Serial.print(p2,4);
              Serial.print("\trVelocity: ");
              Serial.print(v2,4);
              Serial.print("\trAcceleration: ");
              Serial.print(accel,4);
              Serial.print("\trScore: ");
              Serial.print(score);
              Serial.print("\n");
              */
              ticks0 = 0; //Reset Counters
              ticks1 = 0;
              ticks2 = 0;
              ticks3++;
              redValue = 0; //Reset values to get next average
              irValue = 0;

            }
          }
        }

        startMillis = currentMillis;
      }
    }

    // Switch LEDs back and forth.
    // PUT IR IN 13, AND RED IN 12
    if(currentMillis - ledMillis >= ledRate) {
      if(first_led == false) {
        digitalWrite(RED,HIGH);
        digitalWrite(IR,LOW);
        first_led = true;
      }
      else {
        digitalWrite(RED,LOW);
        digitalWrite(IR,HIGH);
        first_led = false;
      }
      ledMillis = currentMillis;
    }

    adcAvg += adc0;
    ticks4++;
 }
}

void bluetooth() {
  while(SerialBT.available()){
    received = SerialBT.read();
    //Serial.println(received);
    SerialBT.println(received);
    commandESP32(received);
  }

  if(currentMillis - BLEMillis >= BTRate) { //SerialBT bitrate: ?/s. 100ms works, 50ms does causes hangups (which the LED flashes will reflect) - need better buffering.

      adcAvg = adcAvg / ticks4;
      /*
      char adcString[10], txString[40]; //Should be faster.
      dtostrf(adcAvg, 1, 0, adcString); 
      strcpy(txString,adcString);
      */

      if(ticks3 > 0) {
        ratioAvg = ratioAvg / ticks3;
        posAvg = posAvg / ticks3;

        //velAvg = velAvg / ticks3;
        //accelAvg = accelAvg / tick3;

        //scoreAvg = scoreAvg / ticks3;
        /*
        char ratioString[10], posString[10];

        dtostrf(ratioAvg, 1, 5, ratioString);
        dtostrf(posAvg, 1, 5, posString);

        strcat(txString,",");
        strcat(txString,ratioString);
        strcat(txString,",");
        strcat(txString,posString);

        SerialBT.println(txString);
        */
        SerialBT.println(String(adcAvg,0) + "," + String(ratioAvg,4) + "," + String(posAvg,4));
      }
      else {
        //strcat(txString,",WAIT");
        //SerialBT.println(txString);
        SerialBT.println(String(adcAvg,0) + ",WAIT");
      }

      //String strToSend = "{ratio:"+String(ratioAvg)+",adc:"+String(adc)+"}";
      //SerialBT.write((uint8_t*) buffer, strToSend*sizeof(int32_t)); //Faster to use a binary buffer
      //SerialBT.println(count);
      //count++;

      ratioAvg = 0;
      posAvg = 0;
      adcAvg = 0;
      adc0 = 0;
      ticks3 = 0;
      ticks4 = 0;

      BLEMillis = currentMillis;
      //Serial.println(ESP.getFreeHeap());
    }
  delay(1); //1 ms delay
}

void loop() {
  core_program();
  bluetooth();
}

Debug Messages:

The following is my heap size, it seems steady for a bit then starts to drop. At that point when I interrupt it causes a reboot.

90212 90184 90188 90212 90184 90188 90188 90188 90188 90212 90188 90188 90188 90188 90212 90184 90184 90184 90188 90184 90212 90184 90212 90212 90184 90188 90188 90188 90184 90188 90184 90212 90188 90184 90184 90184 90184 90212 90188 90212 90188 90212 90188 90184 90188 ... 89460 89412 89384 89060 89284 89140 88824 89092 89036 88968 89052 88996 88928 88872 89044 88988 88932 88868 88808 88756 ASSERT_PARAM(512 0), in rwbt.c at line 273 Guru Meditation Error: Core 0 panic'ed (Interrupt wdt timeout on CPU0) Core 0 register dump: PC : 0x40085841 PS : 0x00060434 A0 : 0x800892bc A1 : 0x3ffc05b0
A2 : 0x00000001 A3 : 0x00000000 A4 : 0x00000000 A5 : 0x60008054
A6 : 0x3ffc1030 A7 : 0x60008050 A8 : 0x80085841 A9 : 0x3ffc0590
A10 : 0x00000004 A11 : 0x00000000 A12 : 0x6000804c A13 : 0xffffffff
A14 : 0x00000000 A15 : 0xfffffffc SAR : 0x00000004 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x40085779 LEND : 0x40085780 LCOUNT : 0x00000000
Core 0 was running in ISR context: EPC1 : 0x40089aae EPC2 : 0x00000000 EPC3 : 0x00000000 EPC4 : 0x40085841

Backtrace: 0x40085841:0x3ffc05b0 0x400892b9:0x3ffc05d0 0x4008994b:0x3ffc05f0 0x40081f45:0x3ffc0610 0x40089aab:0x00000000

Core 1 register dump: PC : 0x4017e1ce PS : 0x00060f34 A0 : 0x8008e46a A1 : 0x3ffd1de0
A2 : 0x00000008 A3 : 0x00000001 A4 : 0x00000000 A5 : 0x3ffd1910
A6 : 0x00000000 A7 : 0x00000001 A8 : 0x3ffc829c A9 : 0x3ffc8260
A10 : 0x00000000 A11 : 0x00000001 A12 : 0x8008c8c8 A13 : 0x3ffd1ce0
A14 : 0x00000000 A15 : 0x3ffd1aa0 SAR : 0x00000000 EXCCAUSE: 0x00000005
EXCVADDR: 0x00000000 LBEG : 0x00000000 LEND : 0x00000000 LCOUNT : 0x00000000

Backtrace: 0x4017e1ce:0x3ffd1de0 0x4008e467:0x3ffd1e00

Rebooting... ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) configsip: 0, SPIWP:0xee clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 mode:DIO, clock div:1 load:0x3fff0018,len:4 load:0x3fff001c,len:808 load:0x40078000,len:6084 load:0x40080000,len:6696 entry 0x400802e4 92620

joshbrew commented 5 years ago

Decoding 13 results 0x40085841: r_assert_param at ?? line ? 0x40085779: r_assert_param at ?? line ? 0x40085780: r_assert_param at ?? line ? 0x40089aae: btdm_bb_isr at intc.c line ? 0x40085841: r_assert_param at ?? line ? 0x40085841: r_assert_param at ?? line ? 0x400892b9: r_rwbt_isr at ?? line ? 0x4008994b: r_rwbtdm_isr_wrapper at intc.c line ? 0x40081f45: _xt_lowint1 at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/xtensa_vectors.S line 1105 0x40089aab: btdm_bb_isr at intc.c line ? 0x4017e1ce: cxa_guard_dummy at ?? line ? 0x4017e1ce: cxa_guard_dummy at ?? line ? 0x4008e467: prvIdleTask at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 3564

joshbrew commented 5 years ago

Another stack trace: 0x40085841: r_assert_param at ?? line ? 0x40085779: r_assert_param at ?? line ? 0x40085780: r_assert_param at ?? line ? 0x40089aae: btdm_bb_isr at intc.c line ? 0x40085841: r_assert_param at ?? line ? 0x40085841: r_assert_param at ?? line ? 0x400892b9: r_rwbt_isr at ?? line ? 0x4008994b: r_rwbtdm_isr_wrapper at intc.c line ? 0x40081f45: _xt_lowint1 at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/xtensa_vectors.S line 1105 0x40089aab: btdm_bb_isr at intc.c line ? 0x4017e1fa: esp_vApplicationWaitiHook at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/freertos_hooks.c line 66 0x4017e1fa: esp_vApplicationWaitiHook at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/esp32/freertos_hooks.c line 66 0x4008e467: prvIdleTask at /Users/ficeto/Desktop/ESP32/ESP32/esp-idf-public/components/freertos/tasks.c line 3564

joshbrew commented 5 years ago

Another note, my heap size doubled when I changed my bluetooth transmit rate from 333 to 100ms. Wtf lol

copercini commented 5 years ago

Interrupt wdt timeout on CPU0 means that you should feed the WDT timer on loops, calling feedLoopWDT(); or delay(10); with 10 or more

joshbrew commented 5 years ago

Thank you for the assist

So should I change the 1ms delay to 10 or change it to feedLoopWDT(). I have some processes that are running at 2ms intervals so I also need to desynchronize then if my delay is longer, unless I just have that delay after a SerialBT print call. I'm working on a biofeedback device that relies on the ADC running pretty fast.

joshbrew commented 5 years ago

Okay, fix: changed the delay after the BTserial send to 10ms, and I have a 1ms delay in the main loop for good measure, now my heap at slower response rates is restored and there are no more crashes so far