need to understand source of crash : "Cache disabled but cached memory region accessed"

pataga
Posts: 73
Joined: Sat Aug 12, 2017 5:53 am

need to understand source of crash : "Cache disabled but cached memory region accessed"

Postby pataga » Fri Feb 09, 2018 5:09 am

Hi,

I seem to have introduced a problem in my code recently and can't figure out why. As per the trace, the panic is from the external gpio interrupt handler, but I have no idea how to resolve it ... so if anyone can explain what i'm doing wrong here, would appreciate it !

Code: Select all

--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
I (10) boot: ESP-IDF v3.1-dev-256-gffd4187 2nd stage bootloader
I (10) boot: compile time 09:01:28
I (10) boot: Enabling RNG early entropy source...
I (15) boot: SPI Speed      : 40MHz
I (19) boot: SPI Mode       : DIO
I (23) boot: SPI Flash Size : 4MB
I (27) boot: Partition Table:
I (31) boot: ## Label            Usage          Type ST Offset   Length
I (38) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (45) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (53) boot:  2 factory          factory app      00 00 00010000 00100000
I (60) boot: End of partition table
I (64) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x0af5c ( 44892) map
I (89) esp_image: segment 1: paddr=0x0001af84 vaddr=0x3ffb0000 size=0x02294 (  8852) load
I (93) esp_image: segment 2: paddr=0x0001d220 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/hari/esp32/esp-idf/components/freertos/./xtensa_vectors.S:1685

I (96) esp_image: segment 3: paddr=0x0001d628 vaddr=0x40080400 size=0x029e8 ( 10728) load
I (109) esp_image: segment 4: paddr=0x00020018 vaddr=0x400d0018 size=0x1bdc8 (114120) map
0x400d0018: _stext at ??:?

I (153) esp_image: segment 5: paddr=0x0003bde8 vaddr=0x40082de8 size=0x068c8 ( 26824) load
0x40082de8: _times_r at /home/hari/esp32/esp-idf/components/newlib/./time.c:162

I (164) esp_image: segment 6: paddr=0x000426b8 vaddr=0x400c0000 size=0x00000 (     0) load
I (170) boot: Loaded app from partition at offset 0x10000
I (170) boot: Disabling RNG early entropy source...
I (174) cpu_start: Pro cpu up.
I (177) cpu_start: Starting app cpu, entry point is 0x40080ea0
0x40080ea0: call_start_cpu1 at /home/hari/esp32/esp-idf/components/esp32/./cpu_start.c:215

I (0) cpu_start: App cpu up.
I (188) heap_init: Initializing. RAM available for dynamic allocation:
I (195) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (201) heap_init: At 3FFB3480 len 0002CB80 (178 KiB): DRAM
I (207) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (213) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (220) heap_init: At 400896B0 len 00016950 (90 KiB): IRAM
I (226) cpu_start: Pro cpu start user code
I (245) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (247) main: gpsvario compiled on Feb  9 2018 at 10:29:51
I (367) nvs: Opening Non-Volatile Storage (NVS) handle... 
I (377) nvs: gxBias = -87
I (377) nvs: gyBias = 106
I (377) nvs: gzBias = -10
I (377) nvs: axBias = -100
I (377) nvs: ayBias = -158
I (387) nvs: azBias = -359
I (387) nvs: mxBias is not initialized yet!
I (397) nvs: myBias value is not initialized yet!
I (397) nvs: mzBias value is not initialized yet!
I (407) nvs: mxSensitivity is not initialized yet!
I (407) nvs: mySensitivity value is not initialized yet!
I (417) nvs: mzSensitivity value is not initialized yet!
I (657) main: battery voltage = 4.056V
I (677) SpiFlashLog: Lo 107018 mid 107020 hi 107022
I (677) SpiFlashLog: FlashLogFreeAddress = 00107020
I (687) main: imubaro task started
I (687) main: gps task started
I (687) Gps: Testing UBX 115200
I (737) Gps: Found UBX packet at 115200 baud
I (737) Gps: configuring @115200baud
I (2147) mpu9250: Calibrating gyro
I (2747) mpu9250: Num Tries = 1
I (2747) mpu9250: gxBias = -86
I (2747) mpu9250: gyBias = 105
I (2747) mpu9250: gzBias = -11
Guru Meditation Error: Core  1 panic'ed (Cache disabled but cached memory region accessed)
Core 1 register dump:
PC      : 0x400d2880  PS      : 0x00060034  A0      : 0x40082330  A1      : 0x3ffb0bf0  
0x400d2880: drdyHandler at /home/hari/esp32/gpsvario/main/./app_main.c:103

0x40082330: _xt_lowint1 at /home/hari/esp32/esp-idf/components/freertos/./xtensa_vectors.S:1105

A2      : 0x00000004  A3      : 0x00000000  A4      : 0x00000010  A5      : 0x40086518  
0x40086518: _frxt_int_enter at /home/hari/esp32/esp-idf/components/freertos/./portasm.S:119

A6      : 0x00000003  A7      : 0x00060523  A8      : 0x80082a18  A9      : 0x00000001  
A10     : 0x00060523  A11     : 0xb0000000  A12     : 0x80085401  A13     : 0x3ffb7560  
A14     : 0x00000003  A15     : 0x00060923  SAR     : 0x00000017  EXCCAUSE: 0x00000007  
EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  
Core 1 was running in ISR context:
EPC1    : 0x4000bff0  EPC2    : 0x00000000  EPC3    : 0x00000000  EPC4    : 0x400d2880
0x400d2880: drdyHandler at /home/hari/esp32/gpsvario/main/./app_main.c:103


Backtrace: 0x400d2880:0x3ffb0bf0 0x4008232d:0x3ffb0c10 0x4000bfed:0x00000000
0x400d2880: drdyHandler at /home/hari/esp32/gpsvario/main/./app_main.c:103

0x4008232d: _xt_lowint1 at /home/hari/esp32/esp-idf/components/freertos/./xtensa_vectors.S:1105


Rebooting...
I (10) boot: ESP-IDF v3.1-dev-256-gffd4187 2nd stage bootloader
I (10) boot: compile time 09:01:28
I (10) boot: Enabling RNG early entropy source...
I (14) boot: SPI Speed      : 40MHz
I (19) boot: SPI Mode       : DIO
I (23) boot: SPI Flash Size : 4MB
I (27) boot: Partition Table:
I (30) boot: ## Label            Usage          Type ST Offset   Length
I (38) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (45) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (52) boot:  2 factory          factory app      00 00 00010000 00100000
I (60) boot: End of partition table
I (64) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x0af5c ( 44892) map
I (89) esp_image: segment 1: paddr=0x0001af84 vaddr=0x3ffb0000 size=0x02294 (  8852) load
I (92) esp_image: segment 2: paddr=0x0001d220 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/hari/esp32/esp-idf/components/freertos/./xtensa_vectors.S:1685

I (96) esp_image: segment 3: paddr=0x0001d628 vaddr=0x40080400 size=0x029e8 ( 10728) load
I (108) esp_image: segment 4: paddr=0x00020018 vaddr=0x400d0018 size=0x1bdc8 (114120) map
0x400d0018: _stext at ??:?

I (153) esp_image: segment 5: paddr=0x0003bde8 vaddr=0x40082de8 size=0x068c8 ( 26824) load
0x40082de8: _times_r at /home/hari/esp32/esp-idf/components/newlib/./time.c:162

I (164) esp_image: segment 6: paddr=0x000426b8 vaddr=0x400c0000 size=0x00000 (     0) load
I (170) boot: Loaded app from partition at offset 0x10000
I (170) boot: Disabling RNG early entropy source...
I (173) cpu_start: Pro cpu up.
I (177) cpu_start: Starting app cpu, entry point is 0x40080ea0
0x40080ea0: call_start_cpu1 at /home/hari/esp32/esp-idf/components/esp32/./cpu_start.c:215

I (0) cpu_start: App cpu up.
I (188) heap_init: Initializing. RAM available for dynamic allocation:
I (194) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (200) heap_init: At 3FFB3480 len 0002CB80 (178 KiB): DRAM
I (207) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (213) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (219) heap_init: At 400896B0 len 00016950 (90 KiB): IRAM
I (226) cpu_start: Pro cpu start user code
I (244) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (246) main: gpsvario compiled on Feb  9 2018 at 10:29:51
I (376) nvs: Opening Non-Volatile Storage (NVS) handle... 
I (376) nvs: gxBias = -87
I (376) nvs: gyBias = 106
I (376) nvs: gzBias = -10
I (376) nvs: axBias = -100
I (376) nvs: ayBias = -158
I (386) nvs: azBias = -359
I (386) nvs: mxBias is not initialized yet!
I (396) nvs: myBias value is not initialized yet!
I (396) nvs: mzBias value is not initialized yet!
I (406) nvs: mxSensitivity is not initialized yet!
I (406) nvs: mySensitivity value is not initialized yet!
I (416) nvs: mzSensitivity value is not initialized yet!
I (656) main: battery voltage = 4.052V
I (676) SpiFlashLog: Lo 107018 mid 107020 hi 107022
I (676) SpiFlashLog: FlashLogFreeAddress = 00107020
I (686) main: imubaro task started
I (686) main: gps task started
I (686) Gps: Testing UBX 115200
I (786) Gps: Found UBX packet at 115200 baud
I (786) Gps: configuring @115200baud
I (2146) mpu9250: Calibrating gyro
I (2746) mpu9250: Num Tries = 1
I (2746) mpu9250: gxBias = -87
I (2746) mpu9250: gyBias = 105
I (2746) mpu9250: gzBias = -10
I (2776) MS5611: PROM CRC = 0xf
I (2776) MS5611: Calculated CRC = 0xf
I (2776) MS5611: Calib Coeffs : 56031 58193 35055 31927 31834 28626
I (2936) main: Altitude 844m Temperature 31C
I (3946) main: ax -5.6 ay 1.0 az 1002.8
I (3946) main: gx -0.1 gy 0.2 gz 0.1
I (4946) main: ax -1.2 ay 3.4 az 997.2
I (4946) main: gx -0.0 gy 0.0 gz -0.1
I (5946) main: ax -4.4 ay 2.2 az 997.5
I (5946) main: gx -0.0 gy -0.1 gz -0.1
I (6946) main: ax -7.8 ay 2.4 az 1009.9
I (6946) main: gx -0.1 gy 0.2 gz 0.2
I (7946) main: ax -6.6 ay -1.5 az 998.4
I (7946) main: gx 0.0 gy 0.0 gz 0.0
I (8946) main: ax -0.5 ay 2.7 az 1002.1
I (8946) main: gx -0.1 gy 0.0 gz -0.1
I (9946) main: ax -5.6 ay 4.2 az 997.2
I (9946) main: gx -0.1 gy 0.1 gz -0.0
I (10946) main: ax -2.7 ay 1.0 az 1000.1
I (10946) main: gx -0.1 gy 0.1 gz -0.1
I (11946) main: ax -5.9 ay -0.7 az 1001.8
I (11946) main: gx 0.2 gy 0.2 gz 0.0
I (12946) main: ax -1.7 ay 2.0 az 999.9
I (12946) main: gx -0.1 gy -0.2 gz -0.1

...
So after i flash the code, it panics on first run, but on rebooting no problem in this case shown above. That's not always true, sometimes it panics on each reboot.

The relevant code is

Code: Select all


volatile SemaphoreHandle_t drdySemaphore;
volatile int drdyFlag = 0;

void pinConfig() {	
   pinMode(pinLcdRST, OUTPUT);
	pinMode(pinLcdCS, OUTPUT);
	pinMode(pinLcdRS, OUTPUT);
	pinMode(pinLcdBklt, OUTPUT);
   LCD_RST_HI();
	LCD_CS_HI();
	LCD_BKLT_OFF();
	
   pinMode(pinBtn0, INPUT); // external 10K pullup
   pinMode(pinBtnL, INPUT); // external 10K pullup
   pinMode(pinBtnM, INPUT); // external 10K pullup
   pinMode(pinBtnR, INPUT); // external 10K pullup
	
	pinMode(pinFlashCS, OUTPUT);
	pinMode(pinImuCS, OUTPUT);
	pinMode(pinBaroCS, OUTPUT);
	FLASH_CS_HI();
	BARO_CS_HI();
	IMU_CS_HI();
	
	pinMode(pinLED, OUTPUT);
	LED_OFF();
	
   pinMode(pinAudioEna, OUTPUT);
   AUDIO_DISABLE();

	pinMode(pinDRDYINT, INPUT); // external 10K pullup
	}



static void gps_task() {
	ESP_LOGI(TAG, "gps task started");
   if (gps_Config() < 0) {
      ESP_LOGE(TAG, "error configuring gps");
      while(1) {delayMs(100);}
      }

   while(1) {
      gps_StateMachine();
      }
   }  


void drdyHandler(void) {
	drdyFlag = 1;
	BaseType_t xHigherPriorityTaskWoken = pdFALSE;
	xSemaphoreGiveFromISR(drdySemaphore, &xHigherPriorityTaskWoken);
    if( xHigherPriorityTaskWoken == pdTRUE) {
        portYIELD_FROM_ISR(); // this wakes up imubaro_task immediately instead of on next FreeRTOS tick
		}
	//LED_TOGGLE();
	}


static void imubaro_task() {
	float gx, gy, gz, ax, ay, az, mx, my, mz;
   //float gxNEDdps, gyNEDdps, gzNEDdps, axNEDmG, ayNEDmG, azNEDmG, mxNED, myNED, mzNED;

	ESP_LOGI(TAG, "imubaro task started");
	vspi_SetFreq(VSPI_CLK_CONFIG_FREQHZ);

   if (mpu9250_config() < 0) {
      ESP_LOGE(TAG, "error mpu9250 config");
      while (1) {delayMs(100)};
      }
	drdySemaphore = xSemaphoreCreateBinary();
	attachInterrupt(pinDRDYINT, drdyHandler, RISING);

   mpu9250_calibrateGyro();
   nvs_SaveGyro();
  // mpu9250_calibrateAccel();
  //nvs_SaveAccel();

	if (!ms5611_Configure()) {
		ESP_LOGE(TAG, "Failure configuring MS5611");
		lcd_printf(0,24, "Bad Baro");
		while (1) {
			LED_ON();
			delayMs(100);
			LED_OFF();
			delayMs(100);
			}
		}	
   ms5611_AveragedSample(4);
	int altMeters = (int)(zCmAvg/100.0f);
	int tCelsius = (int)celsiusSample;
   ESP_LOGI(TAG,"Altitude %dm Temperature %dC", altMeters, tCelsius);
	ms5611_InitializeSampleStateMachine();
	delayMs(MS5611_SAMPLE_PERIOD_MS);

	vspi_SetFreq(VSPI_CLK_HIGH_FREQHZ);

   int drdyCounter = 0;   
   int baroSampleCounter = 0;

   while (1) {
  		xSemaphoreTake(drdySemaphore, portMAX_DELAY);
      drdyCounter++;
      baroSampleCounter++;
      mpu9250_getAccelGyroMagData(&ax, &ay, &az, &gx, &gy, &gz, &mx, &my, &mz);
      if (drdyCounter >= 500) {
         drdyCounter = 0;
         ESP_LOGI(TAG,"ax %.1f ay %.1f az %.1f", ax, ay, az);
         ESP_LOGI(TAG,"gx %.1f gy %.1f gz %.1f", gx, gy, gz);
        // ESP_LOGI(TAG,"mx %.1f my %.1f mz %.1f", mx, my, mz);
        // ESP_LOGI(TAG,"baro alt %dcm", (int)zCmSample);
         }
      if (baroSampleCounter >= 5) {
         baroSampleCounter = 0; // 10mS sample interval
         // temperature + pressure => 20mS for a new altitude sample
		   int zMeasurementAvailable = ms5611_SampleStateMachine();
	      } // baroSampleCounter
      }
}


void app_main() {
	pinConfig();
	ESP_LOGI(TAG, "gpsvario compiled on %s at %s", __DATE__, __TIME__);

	delayMs(100);
   nvs_Init();

   hspi_Config(pinHSCLK, pinHMOSI, pinHMISO, HSPI_CLK_FREQHZ);
   hspi_SetFreq(HSPI_CLK_FREQHZ);
   delayMs(20);
	lcd_Init();
	lcd_Clear();
   lcd_setFont(microsoftSansSerif_14ptBmp);
   // 10k+3k resistor divider,measured 0.949V with a battery voltage of 4.1V
   uint32_t batteryVoltagemV = (4.1f/0.949f)*adc_Sample();
   ESP_LOGI(TAG, "battery voltage = %d.%03dV", batteryVoltagemV/1000, batteryVoltagemV%1000);
   lcd_Printf(0,0,"BAT %d.%03dV", batteryVoltagemV/1000, batteryVoltagemV%1000);

	vspi_Config(pinVSCLK, pinVMOSI, pinVMISO, VSPI_CLK_CONFIG_FREQHZ);

	if (FlashLog_Init() < 0) {
		ESP_LOGE(TAG, "Spi flash log error");
		lcd_Printf(1,0,"Flash Error");		
		while (1) {
			LED_ON();
			delayMs(100);
			LED_OFF();
			delayMs(100);
			}
		}

	lcd_Printf(1,0,"Flash %08d",  FlashLogFreeAddress);
	
	xTaskCreatePinnedToCore(&imubaro_task, "imubarotask", 2048, NULL, 20, NULL, 1);
	xTaskCreatePinnedToCore(&gps_task, "gpstask", 2048, NULL, 20, NULL, 0);
	xTaskCreatePinnedToCore(&display_task, "displaytask", 2048, NULL, 20, NULL, 0);

	while(1) {
      btn_Debounce();
      delayMs(30);
      }
	}

WiFive
Posts: 3529
Joined: Tue Dec 01, 2015 7:35 am

Re: need to understand source of crash : "Cache disabled but cached memory region accessed"

Postby WiFive » Fri Feb 09, 2018 5:48 am

Your handler is not in iram

pataga
Posts: 73
Joined: Sat Aug 12, 2017 5:53 am

Re: need to understand source of crash : "Cache disabled but cached memory region accessed"

Postby pataga » Fri Feb 09, 2018 6:47 am

Your handler is not in iram
Thanks ! That fixed it

Who is online

Users browsing this forum: Majestic-12 [Bot] and 80 guests