Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed)

obcd007
Posts: 1
Joined: Thu Nov 05, 2020 10:14 am

Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed)

Postby obcd007 » Thu Nov 05, 2020 11:00 am

I am trying to create a pager receiver using the t-watch 2020 platform.

The idea is to have a number of transmitters broadcast an esp-now message every seconds.
The receiving watch will wakeup from softsleep every 5 - 10 seconds and listen for the esp-now message.
If nothing needs to be displayed, it will return to light sleep.

So I created a thread on core O that is resumed to receive the messages.
  1.  
  2.     xTaskCreatePinnedToCore(  pager_main_sync_Task,             /* Function to implement the task */
  3.                               "pager main sync Task",   /* Name of the task */
  4.                               5000,                     /* Stack size in words */
  5.                               NULL,                     /* Task input parameter */
  6.                               2,                        /* Priority of the task */
  7.                               &_pager_main_sync_Task,   /* Task handle. */
  8.                               0 );                      /* Core to which the task is tied */
  9.  


Wifi is initialised like this:
  1.  
  2. void pager_app_main_init_wifi()
  3. {
  4.    
  5.     wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
  6.     ESP_ERROR_CHECK( esp_wifi_init(&cfg) );
  7.  
  8.     if (esp_wifi_set_storage(WIFI_STORAGE_RAM) != ESP_OK)
  9.     {
  10.         log_e("Error setting wifi storage area in ram");
  11.     }
  12.    
  13.     esp_wifi_set_mode (WIFI_MODE_STA);
  14.  
  15.    
  16.     if(esp_wifi_start() != ESP_OK){
  17.         log_e("Error initialising Wifi");
  18.     }
  19.     esp_wifi_set_protocol(WIFI_IF_STA, WIFI_PROTOCOL_11B|WIFI_PROTOCOL_11G|WIFI_PROTOCOL_11N|WIFI_PROTOCOL_LR);
  20.  
  21.     esp_wifi_set_promiscuous(true);
  22. //here we need the correct channel
  23.     uint8_t primaryChan = WIFI_CHANNEL;
  24.     wifi_second_chan_t secondChan = WIFI_SECOND_CHAN_NONE;
  25.     esp_wifi_set_channel(primaryChan, secondChan);
  26.     esp_wifi_set_promiscuous(false);
  27.  
  28.     esp_wifi_stop();
  29.     esp_wifi_set_mode(WIFI_MODE_NULL);
  30. }
  31.  
And finally, the worker thread looks like this:
  1. void pager_main_sync_Task( void * pvParameters ) {
  2.     int32_t retval = -1;
  3.     uint64_t t_now_us;
  4.     uint64_t t_early_us;
  5.     uint64_t late_us;
  6.     uint64_t t_start,t_ff;
  7.     bool receive_on;
  8.     log_i("start pager main task, heap: %d", ESP.getFreeHeap() );
  9.  
  10.    
  11.     while (1)
  12.     {
  13.         //we wait until we need to receive a message
  14.         vTaskSuspend(_pager_main_sync_Task);
  15.         pager_set_event(PAGER_RECEIVING);
  16.        
  17.         //if powermgm didnt have a proper wakeup time
  18.         //this likely won't be synced with the transmitter     
  19.         if (powermgm_get_event(POWERMGM_PAGER_LOST))
  20.         {
  21.             powermgm_clear_event( POWERMGM_PAGER_LOST );           
  22.             log_e("powermgm resync forced");
  23.             pager_app_main_force_resync();
  24.         }          
  25.  
  26.         receive_on = false;
  27.         t_now_us = esp_timer_get_time();
  28.        
  29.         // this means that the predictive receive moment has passed (is normal)
  30.         if (t_now_us > pager_app_main_sync.t_predicted_receive)
  31.         {
  32.             // it's not normal it has passed over a minute
  33.             if ((t_now_us - pager_app_main_sync.t_predicted_receive) > 60000000)
  34.             {
  35.                 log_e("pager_app_main_sync.t_predicted_receive has elapsed a minute");
  36.                 pager_app_main_sync.t_predicted_receive = t_now_us + (2 * 1000000);                
  37.             }
  38.             else
  39.             {
  40.                 //if it has passed more than 25ms we should reschedule
  41.                 late_us = t_now_us - pager_app_main_sync.t_predicted_receive;
  42.                 //this was 25000
  43.                 if (late_us > 100000)
  44.                 {
  45.                     log_e("pager_app_main_sync.t_predicted_receive has elapsed.. reschedule");
  46.                     log_e("t_now_us = %lu",t_now_us);
  47.                     log_e("pager_app_main_sync.t_predicted_receive = %lu",pager_app_main_sync.t_predicted_receive);
  48.                
  49.                     //we should schedule a new receive moment and call it a day
  50.                     while(t_now_us > pager_app_main_sync.t_predicted_receive)
  51.                     {
  52.                         pager_app_main_sync.t_predicted_receive = pager_app_main_sync.t_predicted_receive + (2 * 1000000);
  53.                     }
  54.                     if ((pager_app_main_sync.t_predicted_receive - t_now_us) < 150000000)
  55.                     {
  56.                         pager_app_main_sync.t_predicted_receive = pager_app_main_sync.t_predicted_receive + (2 * 1000000);
  57.                     }                  
  58.                     //temporary to see if it fixes our issues
  59.                     //pager_app_main_sync.t_predicted_receive = t_now_us + (2 * 1000000);                  
  60.  
  61.                 }
  62.                 else
  63.                 {
  64.                     receive_on = true;
  65.  
  66.                 }
  67.             }  
  68.         }
  69.         else
  70.         {
  71.             t_now_us = esp_timer_get_time();
  72.            
  73.             //we are here before the expected receive moment
  74.             //kind of strange unless it's due to another wakeup
  75.             t_early_us = pager_app_main_sync.t_predicted_receive - t_now_us;
  76.             //more than 2 seconds early
  77.             if (t_early_us > 2000000)
  78.             {
  79.                 log_e("t_early_us > 2000000 == %lu",t_early_us);
  80.                 //we should go to sleep again till the moment is there
  81.                 //so likely we got here due to another wakeup reason.
  82.             }
  83.             else
  84.             {
  85.                 log_e("t_early_us = %lu",t_early_us);
  86.                 //we just snooze a little before we start consuming power
  87.                 //log_e("we delay from %lu",esp_timer_get_time());
  88.                 vTaskDelay((t_early_us / portTICK_RATE_MS) / 1000);
  89.                 //log_e("After delay  %lu",esp_timer_get_time());
  90.                 late_us = 0;
  91.                 receive_on = true;
  92.             }
  93.         }
  94.        
  95. //disable
  96. //      receive_on = false;
  97.  
  98.  
  99.         if (receive_on == true)
  100.         {
  101. //we are early like 100 ms
  102. //so we just wait some ms of those
  103. //this gives the rest of the hw time to start up       
  104. //we will compensate for being late by waiting shorter     
  105.  
  106. //compensate for clock speed
  107.         if (!pager_app_main_sync.highspeed)
  108.         {
  109.             late_us += 20000;
  110.             log_e("compensating for 80mhz clock");
  111.         }
  112.         vTaskDelay( (PRE_RECEIVE_SUSPEND -(late_us /1000))/ portTICK_RATE_MS);
  113.  
  114.         t_start = esp_timer_get_time();
  115.         pager_clear_event(PAGER_RECEIVED_OK);
  116. /*
  117.         if (esp_wifi_set_storage(WIFI_STORAGE_RAM) != ESP_OK)
  118.         {
  119.             log_e("Error setting wifi storage area in ram");
  120.         }
  121. */     
  122.        
  123.         esp_wifi_set_mode(WIFI_MODE_STA);
  124.  
  125.  
  126.         if(esp_wifi_start() != ESP_OK){
  127.             log_e("Error initialising Wifi");
  128.         }
  129.  
  130.         if (esp_now_init() != ESP_OK) {
  131.             log_e("Error initializing ESP-NOW");
  132.         }
  133.  
  134.         ESP_ERROR_CHECK( esp_now_register_send_cb(pager_app_send_cb) );
  135.         ESP_ERROR_CHECK( esp_now_register_recv_cb(pager_app_recv_cb) );
  136.        
  137.         pager_app_main_sync.t_start_receiver = esp_timer_get_time();
  138.        
  139.         if (pager_app_main_sync.t_start_receiver > pager_app_main_sync.t_predicted_receive)
  140.         {
  141.             log_e("at start receive offset = %lu",pager_app_main_sync.t_start_receiver - pager_app_main_sync.t_predicted_receive);
  142.         }
  143.         else
  144.         {
  145.             log_e("at start receive offset = -%lu",pager_app_main_sync.t_predicted_receive - pager_app_main_sync.t_start_receiver  );
  146.  
  147.         }
  148.         log_e("routine execution time = %lu",pager_app_main_sync.t_start_receiver - t_start);
  149.        
  150.         log_e("waiting for message... fingers crossed");
  151.        
  152.         //we should calculate how much time this took and add it to our receive_gate
  153.         //as it will be longer wen we switch frequency from 240 to 80 Mhz
  154.         //this will prevent a timeout at the switch
  155.        
  156.         if (pager_wait_event(PAGER_RECEIVED_OK,pager_app_main_sync.t_receive_gate))
  157.         {
  158.             log_e ("esp now message received................................");
  159.             pager_app_main_sync.t_prev_message_received = pager_app_main_sync.t_message_received;
  160.             pager_app_main_sync.t_message_received = esp_timer_get_time();
  161.            
  162.             // we calculate the time we need to be ready for the next reception
  163.             // we wakeup 100 ms earlier and just delay before we start wifi.
  164.             // so things should stay in sync if the wakeup is due to siomething different.
  165.             pager_app_main_sync.t_predicted_receive = pager_app_main_sync.t_message_received + (10 * 1000000) - RECEIVE_TIME_BOARDING;
  166.             powermgm_set_rectime(pager_app_main_sync.t_predicted_receive);
  167.             pager_app_main_sync.receive_timeout = 0;
  168.             pager_app_main_sync.t_receive_gate = RECEIVE_TIME_NORMAL;
  169.  
  170.             //this is for info
  171.             if (pager_app_main_sync.tot_receive_ok < 99999)
  172.             {
  173.                 pager_app_main_sync.tot_receive_ok++;
  174.             }
  175.            
  176.             if (pager_app_main_sync.resync)
  177.             {
  178.                 //we got our first rx
  179.                 pager_app_main_sync.resync = false;
  180.                 //pager_app_main_sync.t_sleep = 4090000;
  181.                 pager_app_main_sync.t_sleep = SLEEP_TIME_NORMAL;
  182.                 //pager_app_main_sync.t_receive_gate = RECEIVE_TIME_NORMAL;
  183.            
  184.             }
  185.             else
  186.             {
  187.                 pager_app_main_sync.t_offset = (pager_app_main_sync.t_message_received - pager_app_main_sync.t_start_receiver);
  188.                 log_e("receive gate = %lu",pager_app_main_sync.t_offset);
  189.                 //log_e("receive timeouts = %lu total timeouts = %lu\n",pager_app_main_sync.receive_timeout,pager_app_main_sync.tot_receive_timeout);
  190.                 log_e("receive_interval = %lu",pager_app_main_sync.t_message_received - pager_app_main_sync.t_prev_message_received);
  191.             }
  192.             //once PAGER_RECEIVED_OK is set we will not touch the contents of our receive buffer
  193.             //so we can read it out and use it how we like
  194.              
  195.  
  196.             pager_clear_event(PAGER_RECEIVED_OK);
  197.            
  198.             //the message contains how much messages we can expect
  199.             //and also it's order in the message queue
  200.             //so you can calculate how long to wait for the last message
  201.             //but why would you unless you need to sent something back
  202.         }
  203.         else
  204.         {
  205.             //we didn't receive a thing
  206.             //timeout
  207.            
  208.             //maybe we should disable wifi here already        
  209.  
  210.             //this is for timeout info
  211.             if (pager_app_main_sync.tot_receive_timeout < 99999)
  212.             {
  213.                 pager_app_main_sync.tot_receive_timeout++;
  214.             }
  215.  
  216.             //this is for resync
  217.             if (pager_app_main_sync.receive_timeout <= RETRIES_BEFORE_RESYNC)
  218.             {
  219.                 pager_app_main_sync.receive_timeout++;
  220.                 // 5 times no reception
  221.                 if (pager_app_main_sync.receive_timeout > RETRIES_BEFORE_RESYNC)
  222.                 {
  223.  
  224.                     pager_app_main_sync.resync = true;
  225.                     pager_app_main_sync.t_sleep = SLEEP_TIME_LONG;
  226.                     pager_app_main_sync.t_receive_gate = RECEIVE_TIME_LONG;
  227.                     log_e("resyncing pager due to signal lost.....");
  228.                     if (pager_app_main_sync.tot_resync < 99999)
  229.                     {
  230.                         pager_app_main_sync.tot_resync++;
  231.                     }
  232.                 }
  233.             }
  234.             pager_app_main_sync.t_offset = (esp_timer_get_time() - pager_app_main_sync.t_start_receiver);
  235.             log_e("receive gate at timeout = %lu",pager_app_main_sync.t_offset);
  236.             // log_e("receive timeouts = %lu",pager_app_main_sync.tot_receive_timeout);
  237.  
  238.             //we calculate a receive time
  239.             //so that a non received message doesn't desync
  240.             //we missed a message received so the timer is still on previous
  241.            
  242.             if (!pager_app_main_sync.resync)
  243.             {
  244.                 // we wait for 2 seconds and try again
  245.                 // receive_time boarding was already calculated in t_predicted_receive
  246.                 // so we don't calculate that in again
  247.                 // basically our timing should still be correct
  248.                 pager_app_main_sync.t_predicted_receive = pager_app_main_sync.t_predicted_receive + (2 * 1000000);             
  249.             }
  250.             else
  251.             {
  252.                 pager_app_main_sync.t_predicted_receive = esp_timer_get_time() + (120 * 1000000);
  253.             }
  254.             powermgm_set_rectime(pager_app_main_sync.t_predicted_receive);
  255.  
  256.             //if 2 many timeouts we should resync
  257.             //and maybe set the interval to 30 seconds
  258.             //as we should,open the gate for a larger period
  259.        
  260.         }
  261.         esp_now_deinit();
  262.         esp_wifi_stop();
  263.         esp_wifi_set_mode(WIFI_MODE_NULL);
  264.        
  265.         //so if pager info is showing it should update
  266.         pager_set_event(PAGER_INFO_VALID);
  267.         }
  268. // we didn't attempt to receive        
  269. // so the next tx interval was already calculated
  270.         else
  271.         {
  272.             powermgm_set_rectime(pager_app_main_sync.t_predicted_receive);
  273.         }
  274.        
  275.  
  276.  
  277.         pager_set_event(PAGER_STANDBY_WAIT);
  278. // this will block sleep
  279.         pager_clear_event(PAGER_RECEIVING);
  280.  
  281.         if (powermgm_get_event(POWERMGM_PAGER_WAKEUP))
  282.         {  
  283.             powermgm_set_event( POWERMGM_STANDBY_REQUEST );
  284.         }
  285.        
  286.         log_e("receive ok = %lu receive timeouts = %lu total timeouts = %lu resync = %lu",pager_app_main_sync.tot_receive_ok,pager_app_main_sync.receive_timeout,pager_app_main_sync.tot_receive_timeout,pager_app_main_sync.tot_resync);
  287.         log_e("Expected wakeup time = %lu\n",pager_app_main_sync.t_predicted_receive);
  288.     }
  289.     log_i("finish pager main task, heap: %d", ESP.getFreeHeap() );
  290.     vTaskDelete( NULL );
  291. }
  292.  
The first part of the worker thread basically just looks if the time is there to receive a message so it can keep the modem powered for as short as possible. The system can also wakeup out of light sleep due to other reasons.

This routine runs fine for 2000 - 3000 times and all of sudden throws up a panic:

[E][pager_app_main.cpp:543] pager_main_sync_Task(): compensating for 80mhz clock
Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed)
Core 0 register dump:
PC : 0x4009e5cf PS : 0x00060334 A0 : 0x8008c29b A1 : 0x3ffe5500
A2 : 0x0000a3a0 A3 : 0x3ffe560c A4 : 0x00000020 A5 : 0x00000000
A6 : 0x00000000 A7 : 0x00000000 A8 : 0x00000004 A9 : 0x7c000000
A10 : 0x3ff42020 A11 : 0x0000a3a0 A12 : 0x3ffe560c A13 : 0x00000020
A14 : 0x3ffe57d0 A15 : 0x00000000 SAR : 0x00000000 EXCCAUSE: 0x00000007
EXCVADDR: 0x00000000 LBEG : 0x4000c2e0 LEND : 0x4000c2f6 LCOUNT : 0x00000000

Backtrace: 0x4009e5cf:0x3ffe5500 0x4008c298:0x3ffe5520 0x4015a881:0x3ffe5590 0x40159145:0x3ffe55b0 0x40159785:0x3ffe55d0 0x4015839d:0x3ffe5650 0x4015844c:0x3ffe56d0 0x40157502:0x3ffe5730 0x40157a3d:0x3ffe5770 0x40142ffb:0x3ffe5790 0x40143420:0x3ffe5800 0x401437ee:0x3ffe5830 0x401663f8:0x3ffe5860 0x401664fb:0x3ffe5890 0x4016681a:0x3ffe58c0 0x40162ada:0x3ffe58f0 0x4009a2df:0x3ffe5910 0x400934f9:0x3ffe5950
#0 0x4009e5cf:0x3ffe5500 in esp_rom_spiflash_read at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/spi_flash/spi_flash_rom_patch.c:541
#1 0x4008c298:0x3ffe5520 in spi_flash_read at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/spi_flash/flash_ops.c:567
#2 0x4015a881:0x3ffe5590 in nvs::nvs_flash_read(unsigned int, void*, unsigned int) at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_ops.cpp:70
#3 0x40159145:0x3ffe55b0 in nvs::Page::readEntry(unsigned int, nvs::Item&) const at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_page.cpp:849
#4 0x40159785:0x3ffe55d0 in nvs::Page::readItem(unsigned char, nvs::ItemType, char const*, void*, unsigned int, unsigned char, nvs::VerOffset) at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_page.cpp:849
#5 0x4015839d:0x3ffe5650 in nvs::Storage::readMultiPageBlob(unsigned char, char const*, void*, unsigned int) at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_storage.cpp:557
#6 0x4015844c:0x3ffe56d0 in nvs::Storage::readItem(unsigned char, nvs::ItemType, char const*, void*, unsigned int) at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_storage.cpp:557
#7 0x40157502:0x3ffe5730 in nvs_get_str_or_blob(unsigned int, nvs::ItemType, char const*, void*, unsigned int*) at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_api.cpp:521
#8 0x40157a3d:0x3ffe5770 in nvs_get_blob at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/nvs_flash/src/nvs_api.cpp:525
#9 0x40142ffb:0x3ffe5790 in load_cal_data_from_nvs_handle at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/phy_init.c:428
#10 0x40143420:0x3ffe5800 in esp_phy_load_cal_data_from_nvs at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/phy_init.c:457
#11 0x401437ee:0x3ffe5830 in esp_phy_load_cal_and_init at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp32/phy_init.c:613
#12 0x401663f8:0x3ffe5860 in wifi_rf_phy_enable at ??:?
#13 0x401664fb:0x3ffe5890 in wifi_hw_start at ??:?
#14 0x4016681a:0x3ffe58c0 in wifi_start_process at ??:?
#15 0x40162ada:0x3ffe58f0 in ieee80211_ioctl_process at ??:?
#16 0x4009a2df:0x3ffe5910 in ppTask at ??:?
#17 0x400934f9:0x3ffe5950 in vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c:355 (discriminator 1)

Rebooting...

I understood that wifi stored some information into flash and that this could cause the panic, but I thought that

if (esp_wifi_set_storage(WIFI_STORAGE_RAM) != ESP_OK)
{
log_e("Error setting wifi storage area in ram");
}

would solve that issue.

I tried to change the code so that the working thread only enables wifi with
esp_wifi_set_mode(WIFI_MODE_STA);
and disables it again with
esp_wifi_set_mode(WIFI_MODE_NULL);

this works untill the system enters and resumes light sleep mode. After that, nothing is received anymore.

Once syncronised with the transmitter, the receiver will only be turned on for 200ms. If nothing is received for 10 times, the system will wait for a minute and turn the receiver on for a little over one second. (To prevent battery drainage when being out of range of the transmitting esp modules.

My apologies for the long post. I hope it contains enough information to pinpoint the issue and find a way to prevent it.

Thanks in advance.


Who is online

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