search

Ebiroll / qemu_esp32

Add tensilica esp32 cpu and a board to qemu and dump the rom to learn more about esp-idf
Apache License 2.0
425 stars 53 forks source link

Issue with running latest ESP-IDF code. #16

Closed mrdeep1 closed 5 years ago

mrdeep1 commented 5 years ago

When running with latest esp-idf bbafd506624b2a3d1e58f2dd3154286b79a8632b (and updated tool chain), I get

esp32flash.bin @ FD000000
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:9172
load:0x40078000,len:12636
load:0x40080400,len:7068
csum err:0x57!=0xff
Falling back to built-in command interpreter.
OK

but when running with esp-idf version a20d02b7f196c407bc9f39b781e31a0a4f665968 (Thu Apr 18 2019), I get (correctly) when using the latest qemu_esp32 and qemu-xtensa-esp32 code in both cases

esp32flash.bin @ 27600000
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:9052
load:0x40078000,len:12312
load:0x40080400,len:7140
entry 0x400807a4
D (12) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (4) boot: ESP-IDF v3.3-beta2-474-g90f4379 2nd stage bootloader
I (4) boot: compile time 18:47:57
D (4) boot: Enabling RTCWDT(9000 ms)
I (4) boot: Enabling RNG early entropy source...
... etc

Any clues as to what needs to be done here?

Ebiroll commented 5 years ago

The clue is csum err:0x57!=0xff Maybe the qemu_flash programs needs to be updated.

Den lör 29 juni 2019 01:58mrdeep1 notifications@github.com skrev:

When running with latest esp-idf bbafd506624b2a3d1e58f2dd3154286b79a8632b (and updated tool chain), I get

esp32flash.bin @ FD000000 ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:2 load:0x3fff0018,len:4 load:0x3fff001c,len:9172 load:0x40078000,len:12636 load:0x40080400,len:7068 csum err:0x57!=0xff Falling back to built-in command interpreter. OK

but when running with esp-idf version a20d02b7f196c407bc9f39b781e31a0a4f665968 (Thu Apr 18 2019), I get (correctly) when using the latest qemu_esp32 and qemu-xtensa-esp32 code in both cases

esp32flash.bin @ 27600000 ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:2 load:0x3fff0018,len:4 load:0x3fff001c,len:9052 load:0x40078000,len:12312 load:0x40080400,len:7140 entry 0x400807a4 D (12) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff) I (4) boot: ESP-IDF v3.3-beta2-474-g90f4379 2nd stage bootloader I (4) boot: compile time 18:47:57 D (4) boot: Enabling RTCWDT(9000 ms) I (4) boot: Enabling RNG early entropy source... ... etc

Any clues as to what needs to be done here?

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/Ebiroll/qemu_esp32/issues/16?email_source=notifications&email_token=ACBFZ7GVF2YQS7HTHS63IOTP4ZGLHA5CNFSM4H4HM2RKYY3PNVWWK3TUL52HS4DFUVEXG43VMWVGG33NNVSW45C7NFSM4G4LZSCQ, or mute the thread https://github.com/notifications/unsubscribe-auth/ACBFZ7GURRNBRLPMMMH5GHDP4ZGLHANCNFSM4H4HM2RA .

mrdeep1 commented 5 years ago

OK. That issue was down to the size of bootloader.bin, causing an overlay of partitions_singleapp.bin, which was set up for verbose logging:-

./qemu_flash build/14_basic_webserver.bin            (I have enhanced toflash.c to write out sizes etc.)
4+0 records in
4+0 records out
4194304 bytes (4.2 MB) copied, 0.0254044 s, 165 MB/s
0x00001000-0x000080a0: (28832) build/bootloader/bootloader.bin
0x00008000-0x00008c00: (3072) build/partitions_singleapp.bin
0x00010000-0x000bcc90: (707728) build/14_basic_webserver.bin

which then leads me to the next issue - spi_flash failed to get chip size

esp32flash.bin @ C7400000
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6444
load:0x40078000,len:11652
load:0x40080400,len:6632
entry 0x40080768
I (3) boot: ESP-IDF v3.3-beta2-1089-gbbafd50 2nd stage bootloader
I (4) boot: compile time 14:19:03
I (4) boot: Enabling RNG early entropy source...
I (4) boot: SPI Speed      : 40MHz
I (4) boot: SPI Mode       : DIO
I (4) boot: SPI Flash Size : 4MB
I (4) boot: Partition Table:
I (4) boot: ## Label            Usage          Type ST Offset   Length
I (4) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (4) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (4) boot:  2 factory          factory app      00 00 00010000 00100000
I (4) boot: End of partition table
I (4) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x2eb6c (191340) map
I (29) esp_image: segment 1: paddr=0x0003eb94 vaddr=0x3ffb0000 size=0x0147c (  5244) load
I (30) esp_image: segment 2: paddr=0x00040018 vaddr=0x400d0018 size=0x69ef4 (433908) map
I (87) esp_image: segment 3: paddr=0x000a9f14 vaddr=0x3ffb147c size=0x01cfc (  7420) load
I (89) esp_image: segment 4: paddr=0x000abc18 vaddr=0x40080000 size=0x00400 (  1024) load
I (89) esp_image: segment 5: paddr=0x000ac020 vaddr=0x40080400 size=0x10028 ( 65576) load
HOST RER TBD
I (103) boot: Loaded app from partition at offset 0x10000
I (103) boot: Disabling RNG early entropy source...
I (103) cpu_start: Pro cpu up.
I (103) cpu_start: Application information:
I (104) cpu_start: Project name:     14_basic_webserver
I (104) cpu_start: App version:      92c7258-dirty
I (104) cpu_start: Compile time:     Jun 29 2019 14:19:14
I (104) cpu_start: ELF file SHA256:  e9ad7f9ba5d02ca8...
I (104) cpu_start: ESP-IDF:          v3.3-beta2-1089-gbbafd50
I (104) cpu_start: Starting app cpu, entry point is 0x400810c4
I (0) cpu_start: App cpu up.
I (721) heap_init: Initializing. RAM available for dynamic allocation:
I (721) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (721) heap_init: At 3FFB9BE0 len 00026420 (153 KiB): DRAM
I (722) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (722) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (723) heap_init: At 40090428 len 0000FBD8 (62 KiB): IRAM
I (723) cpu_start: Pro cpu start user code
esp32_i2c_interruptSet: new IRQ val 0x8b7b7a40
TBD(pc = 400879df): .../qemu-xtensa-esp32/target-xtensa/translate.c:1409
E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

I (246) spi_flash: detected chip: generic
E (246) memspi: no response

E (246) spi_flash: failed to get chip size
assertion "flash_ret == ESP_OK" failed: file ".../esp/esp-idf/components/esp32/cpu_start.c", line 408, function: start_cpu0_default
abort() was called at PC 0x400d31ab on core 0
HOST RER TBD

ELF file SHA256: e9ad7f9ba5d02ca8dc953a8786778e14e1eb136edd4e680521183006c93be958

Backtrace: 0x40088f71:0x3ffe3b50 0x400892e9:0x3ffe3b70 0x400d31ab:0x3ffe3b90 0x4008103a:0x3ffe3bc0 0x40081311:0x3ffe3bf0 0x40079393:0x3ffe3c30 |<-CORRUPTED

Rebooting...

More digging I guess - any more clues?

Ebiroll commented 5 years ago

Ok. Thanks for the help. Spi emulation needs to be Improved.

Den lör 29 juni 2019 22:04mrdeep1 notifications@github.com skrev:

OK. That issue was down to the size of bootloader.bin, causing an overlay of partitions_singleapp.bin, which was set up for verbose logging:-

./qemu_flash build/14_basic_webserver.bin (I have enhanced toflash.c to write out sizes etc.) 4+0 records in 4+0 records out 4194304 bytes (4.2 MB) copied, 0.0254044 s, 165 MB/s 0x00001000-0x000080a0: (28832) build/bootloader/bootloader.bin 0x00008000-0x00008c00: (3072) build/partitions_singleapp.bin 0x00010000-0x000bcc90: (707728) build/14_basic_webserver.bin

which then leads me to the next issue - spi_flash failed to get chip size

esp32flash.bin @ C7400000 ets Jun 8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_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:2 load:0x3fff0018,len:4 load:0x3fff001c,len:6444 load:0x40078000,len:11652 load:0x40080400,len:6632 entry 0x40080768 I (3) boot: ESP-IDF v3.3-beta2-1089-gbbafd50 2nd stage bootloader I (4) boot: compile time 14:19:03 I (4) boot: Enabling RNG early entropy source... I (4) boot: SPI Speed : 40MHz I (4) boot: SPI Mode : DIO I (4) boot: SPI Flash Size : 4MB I (4) boot: Partition Table: I (4) boot: ## Label Usage Type ST Offset Length I (4) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (4) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (4) boot: 2 factory factory app 00 00 00010000 00100000 I (4) boot: End of partition table I (4) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x2eb6c (191340) map I (29) esp_image: segment 1: paddr=0x0003eb94 vaddr=0x3ffb0000 size=0x0147c ( 5244) load I (30) esp_image: segment 2: paddr=0x00040018 vaddr=0x400d0018 size=0x69ef4 (433908) map I (87) esp_image: segment 3: paddr=0x000a9f14 vaddr=0x3ffb147c size=0x01cfc ( 7420) load I (89) esp_image: segment 4: paddr=0x000abc18 vaddr=0x40080000 size=0x00400 ( 1024) load I (89) esp_image: segment 5: paddr=0x000ac020 vaddr=0x40080400 size=0x10028 ( 65576) load HOST RER TBD I (103) boot: Loaded app from partition at offset 0x10000 I (103) boot: Disabling RNG early entropy source... I (103) cpu_start: Pro cpu up. I (103) cpu_start: Application information: I (104) cpu_start: Project name: 14_basic_webserver I (104) cpu_start: App version: 92c7258-dirty I (104) cpu_start: Compile time: Jun 29 2019 14:19:14 I (104) cpu_start: ELF file SHA256: e9ad7f9ba5d02ca8... I (104) cpu_start: ESP-IDF: v3.3-beta2-1089-gbbafd50 I (104) cpu_start: Starting app cpu, entry point is 0x400810c4 I (0) cpu_start: App cpu up. I (721) heap_init: Initializing. RAM available for dynamic allocation: I (721) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM I (721) heap_init: At 3FFB9BE0 len 00026420 (153 KiB): DRAM I (722) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (722) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (723) heap_init: At 40090428 len 0000FBD8 (62 KiB): IRAM I (723) cpu_start: Pro cpu start user code esp32_i2c_interruptSet: new IRQ val 0x8b7b7a40 TBD(pc = 400879df): .../qemu-xtensa-esp32/target-xtensa/translate.c:1409 E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (245) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

E (246) memspi: no response

I (246) spi_flash: detected chip: generic E (246) memspi: no response

E (246) spi_flash: failed to get chip size assertion "flash_ret == ESP_OK" failed: file ".../esp/esp-idf/components/esp32/cpu_start.c", line 408, function: start_cpu0_default abort() was called at PC 0x400d31ab on core 0 HOST RER TBD

ELF file SHA256: e9ad7f9ba5d02ca8dc953a8786778e14e1eb136edd4e680521183006c93be958

Backtrace: 0x40088f71:0x3ffe3b50 0x400892e9:0x3ffe3b70 0x400d31ab:0x3ffe3b90 0x4008103a:0x3ffe3bc0 0x40081311:0x3ffe3bf0 0x40079393:0x3ffe3c30 |<-CORRUPTED

Rebooting...

More digging I guess - any more clues?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/Ebiroll/qemu_esp32/issues/16?email_source=notifications&email_token=ACBFZ7EIYSKQONCDMOKEVPTP45TYNA5CNFSM4H4HM2RKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODY3ZLUA#issuecomment-506959312, or mute the thread https://github.com/notifications/unsubscribe-auth/ACBFZ7FFNVC3M56HDLRUVSTP45TYNANCNFSM4H4HM2RA .

mrdeep1 commented 5 years ago

~/esp/qemu_esp32/qemu-patch/hw/xtensa/esp32.c is different to ~/qemu-xtensa-esp32/hw/xtensa/esp32.c . Should the latter get updated?

Ebiroll commented 5 years ago

The one in the patch tree tries to somewhat keep up with the latest version of qemu.

Ebiroll commented 5 years ago

To fix this issue, You have to implement emulation of reading the id from flash. Should be fairly easy, I will try it later.

esp_err_t memspi_host_read_id_hs(spi_flash_host_driver_t chip_drv, uint32_t id) { //NOTE: we do have a read id function, however it doesn't work in high freq spi_flash_trans_t t = { .command = CMD_RDID, .mosi_data = 0, .mosi_len = 0, .miso_len = 24 }; chip_drv->common_command(chip_drv, &t); uint32_t raw_flash_id = t.miso_data[0]; ESP_EARLY_LOGV(TAG, "raw_chip_id: %X\n", raw_flash_id); if (raw_flash_id == 0xFFFFFF || raw_flash_id == 0) { ESP_EARLY_LOGE(TAG, "no response\n"); return ESP_ERR_FLASH_NO_RESPONSE; }

// Byte swap the flash id as it's usually written the other way around
uint8_t mfg_id = raw_flash_id & 0xFF;
uint16_t flash_id = (raw_flash_id >> 16) | (raw_flash_id & 0xFF00);
*id = ((uint32_t)mfg_id << 16) | flash_id;
ESP_EARLY_LOGV(TAG, "chip_id: %X\n", *id);
return ESP_OK;

}

You could set a breakpoints in these,

esp_err_t esp_flash_init_default_chip()
esp_flash_init() detect_spi_flash_chip() spi_flash_hal_common_command(spi_flash_host_driver_t chip_drv, spi_flash_trans_t trans)

Ebiroll commented 5 years ago

Also need to satisfy this function, esp_flash_get_size() which reads the id. spi_flash_chip_generic_detect_size

mrdeep1 commented 5 years ago

I had made this temporary change (esp-idf) to get past this point (as I wanted to test something else)

diff --git a/components/spi_flash/esp_flash_spi_init.c b/components/spi_flash/esp_flash_spi_init.c
index ecd5666..7ba36f7 100644
--- a/components/spi_flash/esp_flash_spi_init.c
+++ b/components/spi_flash/esp_flash_spi_init.c
@@ -185,7 +185,8 @@ esp_err_t esp_flash_init_default_chip()
     // ROM TODO: to account for chips which are slow to power on, maybe keep probing in a loop here
     esp_err_t err = esp_flash_init(&default_chip);
     if (err != ESP_OK) {
-        return err;
+//        return err;
+       default_chip.size = g_rom_flashchip.chip_size;
     }
     if (default_chip.size < g_rom_flashchip.chip_size) {
         ESP_EARLY_LOGE(TAG, "Detected size(%dk) smaller than the size in the binary image header(%dk). Probe failed.",

and then had to make the following change to make sure that all was initialized correctly

diff --git a/components/emul_ip/emul_ip.c b/components/emul_ip/emul_ip.c
index 2d1567c..9111507 100644
--- a/components/emul_ip/emul_ip.c
+++ b/components/emul_ip/emul_ip.c
@@ -60,6 +60,7 @@ void task_lwip_init(void * pParam)
   // From esp-idf
   //lwip_init();
   //sys_init();
+  tcpip_adapter_init();

   //ethernet_hardreset();//hard reset of EthernetDaughterCard
   // This should be done in lwip_init
@@ -108,7 +109,7 @@ void task_lwip_init(void * pParam)

  // Fake got_ip event

- if (esp_event_loop_get_queue()!=NULL) {
+ // if (esp_event_loop_get_queue()!=NULL) {
    system_event_t evt;

    //ip4_addr_set(&ip_info->ip, ip_2_ip4(&netif->ip_addr));
@@ -118,10 +119,12 @@ void task_lwip_init(void * pParam)
    //notify event
    evt.event_id = SYSTEM_EVENT_STA_GOT_IP;

-   memcpy(&evt.event_info.got_ip.ip_info, &ipaddr, sizeof(tcpip_adapter_ip_info_t));
+   memcpy(&evt.event_info.got_ip.ip_info.ip, &ipaddr, sizeof(ipaddr));
+   memcpy(&evt.event_info.got_ip.ip_info.netmask, &netmask, sizeof(netmask));
+   memcpy(&evt.event_info.got_ip.ip_info.gw, &gw, sizeof(gw));

    esp_event_send(&evt);
- }
+ // }
Ebiroll commented 5 years ago

OK. Great. So far I was able to emulate the ID of the chip but not the size.

mrdeep1 commented 5 years ago

I was puzzled by not seeing anything in io.txt when stepping through the code - assumed that qemu was not picking the io transaction (perhaps io space was not properly mapped) and not (yet) understanding how qemu does this I moved on with the above fix

Ebiroll commented 5 years ago

Yes, you will have to patch esp32.c (Remove these) // Redefing for SPI flash

undef DEBUG_LOG

define DEBUG_LOG(...) fprintf(stdout, __VA_ARGS__)

In order to get output to io.txt, However flash SPI operations are very common and will totally fill the log.

mrdeep1 commented 5 years ago

To get the size (4M), you need to do

diff --git a/hw/xtensa/esp32.c b/hw/xtensa/esp32.c
index 57da683..c21464c 100644
--- a/hw/xtensa/esp32.c
+++ b/hw/xtensa/esp32.c
@@ -777,7 +777,7 @@ static void esp32_spi_cmd(Esp32SpiState *s, hwaddr addr,
            DEBUG_LOG("CMD 0x35 (RDSR2) read status register\n");
        }
        if (command==0x1f) { // RDID
-          s->reg[data_w0]=0x409D;  
+          s->reg[data_w0]=0x16409D;  
           // Size ??
           s->reg[data_w1]=0x3E80;
           s->reg[data_w2]=0x00;
Ebiroll commented 5 years ago

Thanks @mrdeep1, I did step through the code but missed this obvious change. Hope your esp32 project is going well. :-)