espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.46k stars 7.25k forks source link

[TW#16425] SD card file system & ethernet compatibility issue #1237

Closed Gfast2 closed 6 years ago

Gfast2 commented 6 years ago

Hi ESP-IDF:

Right now I init the file system of SD card on main_app(). And then fire up the webserver task (mongoose webserver) later when every initialization steps are finished.

Now if I try to in webserver task accessing sd card file system by FILE* fIndex = fopen("/sdcard/index.html", "r");

I got

W (14561) webserver: Now open my new ESP32 index page
E (14561) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0xffffffff
E (14571) diskio_sdmmc: sdmmc_read_blocks failed (-1)
E (14571) webserver: Failed to open file for reading

The code snippet that trigger these errors are:

ESP_LOGW(TAG, "Now open my new ESP32 index page");
FILE* fIndex = fopen("/sdcard/index.html", "r");
if (fIndex == NULL) {
    ESP_LOGE(TAG, "Failed to open file for reading");
    return;
}

The SD card initialization steps are as the example one from esp-idf. And I did checked the file I/O possibility of the file index.html from sd card in another task sd_card which basically the container of the rest part (except the initialization part of the example) of the sd card example. In this task, everything works as fine.

But how can I know what is the problem at all? ⛵️

igrr commented 6 years ago

Could you please enable "verbose" log output level in menuconfig ( http://esp-idf.readthedocs.io/en/latest/api-reference/kconfig.html#log-default-level) and attach the new log you get for this error? Right now the code returns error "-1", which essentially means "any kind of error not handled otherwise". Verbose log should have more information about the cause of the error.

On Tue, Nov 7, 2017 at 7:19 PM, Su notifications@github.com wrote:

Hi ESP-IDF:

Right now I init the file system of SD card on main_app(). And then fire up the webserver task (mongoose webserver) later when every initialization steps are finished.

Now if I try to in webserver task accessing sd card file system by FILE* fIndex = fopen("/sdcard/index.html", "r");

I got

W (14561) webserver: Now open my new ESP32 index page E (14561) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0xffffffff E (14571) diskio_sdmmc: sdmmc_read_blocks failed (-1) E (14571) webserver: Failed to open file for reading

The code snippet that trigger these errors are:

ESP_LOGW(TAG, "Now open my new ESP32 index page"); FILE* fIndex = fopen("/sdcard/index.html", "r"); if (fIndex == NULL) { ESP_LOGE(TAG, "Failed to open file for reading"); return; }

The SD card initialization steps are as the example one from esp-idf. And I did checked the file I/O possibility of the file index.html from sd card in another task sd_card which basically the container of the rest part (except the initialization part of the example) of the sd card example. In this task, everything works as fine.

But how can I know what is the problem at all? ⛵️

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/espressif/esp-idf/issues/1237, or mute the thread https://github.com/notifications/unsubscribe-auth/AEJcet89cSinIMiv2skAdlITY5H1i3ucks5s0Dy1gaJpZM4QUoiw .

Gfast2 commented 6 years ago

Hi @igrr ,

Thanks. This is the error log (V):

Task watchdog got triggered. The following tasks did not feed the watchdog in time:
 - IDLE (CPU 0)
Tasks currently running:
CPU 0: eventTask
CPU 1: btn_task
V (9536) event: enter default callback
D (17486) tcpip_adapter: check: local, if=2 fn=0x401035d0
0x401035d0: tcpip_adapter_up_api at /home/gfast2/esp/esp-idf/components/tcpip_adapter/./tcpip_adapter_lwip.c:1077

D (17486) phy_common: phy_mii_check_link_status(UP)
D (17496) phy_common: phy_mii_check_link_status(UP)
D (17496) tcpip_adapter: call api in lwip: ret=0x0, give sem
D (17506) phy_common: phy_mii_check_link_status(UP)
D (17516) tcpip_adapter: check: remote, if=2 fn=0x401035d0
0x401035d0: tcpip_adapter_up_api at /home/gfast2/esp/esp-idf/components/tcpip_adapter/./tcpip_adapter_lwip.c:1077

D (17516) phy_common: phy_mii_check_link_status(UP)
V (17526) event: exit default callback
D (17526) event: SYSTEM_EVENT_ETH_GOT_IP
V (17536) event: enter default callback
I (17536) event: eth ip: 172.23.23.30, mask: 255.255.0.0, gw: 172.23.23.1
V (17546) event: exit default callback
W (17486) webserver: Now open my new ESP32 index page
V (17486) GPS: Sentence - MINMEA_SENTENCE_GSA
V (17556) vfs_fat: vfs_fat_open: path="/hello.txt", flags=0, mode=1b6
V (17566) GPS: Sentence - MINMEA_SENTENCE_GSV
V (17566) GPS: Sentence - MINMEA_SENTENCE_GSV
V (17576) GPS: Sentence - MINMEA_SENTENCE_GSV
V (17576) sdmmc_cmd: sending cmd slot=1 op=17 arg=233000 flags=1c50 data=0x3ffc06ec blklen=512 datalen=512 timeout=1000
V (17596) GPS: Sentence - MINMEA_SENTENCE_GSV
V (17606) sdmmc_req: make_hw_cmd: opcode=17, rexp=1, crc=1
V (17616) GPS: Sentence - MINMEA_SENTENCE_GSV
V (17616) GPS: Sentence - MINMEA_SENTENCE_GLL
V (17626) GPS: Sentence - MINMEA_SENTENCE_RMC
V (17626) GPS: time: 11:40:57 2017-11-7
V (17626) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=512
V (17656) sdmmc_req: sdmmc_handle_event: evt 00002004 00000000
V (17656) sdmmc_req: process_events: state=SENDING_CMD
V (17646) GPS: Sentence - MINMEA_SENTENCE_VTG
V (17666) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (17676) GPS: Sentence - INVALID
V (17676) GPS: Sentence - MINMEA_SENTENCE_GLL
V (17686) GPS: Sentence - MINMEA_SENTENCE_RMC
D (17686) sdmmc_req: process_data_status: error 0xffffffff (status=00002004)
V (17716) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (17716) sdmmc_req: process_events state=IDLE next_state=IDLE
V (17706) GPS: time: 11:40:58 2017-11-7
V (17726) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0xffffffff state=4
V (17736) GPS: Sentence - MINMEA_SENTENCE_VTG
V (17746) GPS: Sentence - INVALID
V (17746) GPS: Sentence - INVALID
D (17756) rmt: RMT INTR : TX END
E (17746) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0xffffffff
V (17766) GPS: Sentence - INVALID
E (17776) diskio_sdmmc: sdmmc_read_blocks failed (-1)
V (17776) GPS: Sentence - INVALID
V (17776) GPS: Sentence - MINMEA_SENTENCE_GSV
D (17786) vfs_fat: vfs_fat_open: fresult=1
E (17786) webserver: Failed to open file for reading
E (17796) webserver: error is 5
Gfast2 commented 6 years ago

This is the start process of my app_main():

MONITOR
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x3f (SPI_FAST_FLASH_BOOT)
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x3f (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:5552
ho 0 tail 12 room 4
load:0x40078000,len:0
load:0x40078000,len:12532
entry 0x40078f84
I (30) boot: ESP-IDF v3.0-dev-1028-g2c95a77-dirty 2nd stage bootloader
I (30) boot: compile time 12:40:13
I (42) boot: Enabling RNG early entropy source...
I (42) boot: SPI Speed      : 40MHz
I (42) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (49) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (67) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (75) boot:  2 factory          factory app      00 00 00010000 00100000
I (82) boot:  3 storage          Unknown data     01 82 00110000 000f0000
I (90) boot: End of partition table
I (94) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x15b00 ( 88832) map
I (120) esp_image: segment 1: paddr=0x00025b28 vaddr=0x3ffb0000 size=0x024a0 (  9376) load
I (122) esp_image: segment 2: paddr=0x00027fd0 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/gfast2/esp/esp-idf/components/freertos/./xtensa_vectors.S:1685

I (127) esp_image: segment 3: paddr=0x000283d8 vaddr=0x40080400 size=0x07c38 ( 31800) load
I (143) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x44830 (280624) map
0x400d0018: _stext at ??:?

I (200) esp_image: segment 5: paddr=0x00074850 vaddr=0x40088038 size=0x02398 (  9112) load
0x40088038: get_next_block at /home/gfast2/esp/esp-idf/components/heap/./multi_heap.c:116
 (inlined by) multi_heap_realloc_impl at /home/gfast2/esp/esp-idf/components/heap/./multi_heap.c:493

I (202) esp_image: segment 6: paddr=0x00076bf0 vaddr=0x400c0000 size=0x00000 (     0) load
I (208) boot: Loaded app from partition at offset 0x10000
I (212) boot: Disabling RNG early entropy source...
I (218) cpu_start: Pro cpu up.
I (222) cpu_start: Starting app cpu, entry point is 0x40081054
0x40081054: call_start_cpu1 at /home/gfast2/esp/esp-idf/components/esp32/./cpu_start.c:222

I (0) cpu_start: App cpu up.
I (232) heap_init: Initializing. RAM available for dynamic allocation:
D (239) heap_init: New heap initialised at 0x3ffae6e0
I (244) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
D (250) heap_init: New heap initialised at 0x3ffbbe68
I (255) heap_init: At 3FFBBE68 len 00024198 (144 KiB): DRAM
I (261) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (268) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (274) heap_init: New heap initialised at 0x4008a3d0
I (279) heap_init: At 4008A3D0 len 00015C30 (87 KiB): IRAM
I (286) cpu_start: Pro cpu start user code
D (298) clk: RTC_SLOW_CLK calibration value: 3441861
V (8) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (9) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (13) intr_alloc: Connected src 46 to int 2 (cpu 0)
V (19) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (25) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC0E
D (33) intr_alloc: Connected src 57 to int 3 (cpu 0)
V (38) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (44) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (52) intr_alloc: Connected src 16 to int 9 (cpu 0)
V (57) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (63) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (71) intr_alloc: Connected src 24 to int 12 (cpu 0)
I (76) cpu_start: Starting scheduler on PRO CPU.
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (10) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (10) cpu_start: Starting scheduler on APP CPU.
D (126) heap_init: New heap initialised at 0x3ffe0440
D (126) heap_init: New heap initialised at 0x3ffe4350
I (136) eth_example: Initializing SD card
D (136) sdmmc_periph: peripheral version 5342270a, hardware config 03c44c83
V (146) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (156) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (166) intr_alloc: Connected src 37 to int 13 (cpu 0)
D (166) sdmmc_periph: slot=1 div=50 freq=400kHz
D (176) sdmmc_periph: slot=1 width=1
D (176) sdmmc_cmd: sdmmc_card_init
V (176) sdmmc_cmd: sending cmd slot=1 op=0 arg=0 flags=20 data=0x0 blklen=0 datalen=0 timeout=1000
V (186) sdmmc_req: make_hw_cmd: opcode=0, rexp=0, crc=0
V (196) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (196) sdmmc_req: process_events: state=SENDING_CMD
V (206) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (206) sdmmc_req: process_events state=IDLE next_state=IDLE
V (216) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0
V (246) sdmmc_cmd: sending cmd slot=1 op=0 arg=0 flags=20 data=0x0 blklen=0 datalen=0 timeout=1000
V (246) sdmmc_req: make_hw_cmd: opcode=0, rexp=0, crc=0
V (246) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (246) sdmmc_req: process_events: state=SENDING_CMD
V (256) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (266) sdmmc_req: process_events state=IDLE next_state=IDLE
V (266) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0
V (296) sdmmc_cmd: sending cmd slot=1 op=8 arg=1aa flags=1c30 data=0x0 blklen=0 datalen=0 timeout=1000
V (296) sdmmc_req: make_hw_cmd: opcode=8, rexp=1, crc=1
V (296) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (296) sdmmc_req: process_events: state=SENDING_CMD
V (306) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (316) sdmmc_req: process_events state=IDLE next_state=IDLE
V (316) sdmmc_cmd: cmd response 000001aa 00000000 00000000 00000000 err=0x0 state=0
D (326) sdmmc_cmd: SDHC/SDXC card
V (326) sdmmc_cmd: sending cmd slot=1 op=55 arg=0 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (336) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (346) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (346) sdmmc_req: process_events: state=SENDING_CMD
V (356) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (356) sdmmc_req: process_events state=IDLE next_state=IDLE
V (366) sdmmc_cmd: cmd response 00000120 00000000 00000000 00000000 err=0x0 state=0
V (376) sdmmc_cmd: sending cmd slot=1 op=41 arg=40ff8000 flags=1030 data=0x0 blklen=0 datalen=0 timeout=1000
V (386) sdmmc_req: make_hw_cmd: opcode=41, rexp=1, crc=0
V (386) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (396) sdmmc_req: process_events: state=SENDING_CMD
V (396) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (406) sdmmc_req: process_events state=IDLE next_state=IDLE
V (416) sdmmc_cmd: cmd response 00ff8000 00000000 00000000 00000000 err=0x0 state=0
V (426) sdmmc_cmd: sending cmd slot=1 op=55 arg=0 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (426) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (436) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (436) sdmmc_req: process_events: state=SENDING_CMD
V (446) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (456) sdmmc_req: process_events state=IDLE next_state=IDLE
V (456) sdmmc_cmd: cmd response 00000120 00000000 00000000 00000000 err=0x0 state=0
V (466) sdmmc_cmd: sending cmd slot=1 op=41 arg=40ff8000 flags=1030 data=0x0 blklen=0 datalen=0 timeout=1000
V (476) sdmmc_req: make_hw_cmd: opcode=41, rexp=1, crc=0
V (476) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (486) sdmmc_req: process_events: state=SENDING_CMD
V (486) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (496) sdmmc_req: process_events state=IDLE next_state=IDLE
V (506) sdmmc_cmd: cmd response 80ff8000 00000000 00000000 00000000 err=0x0 state=0
D (506) sdmmc_cmd: host_ocr=0x40ff8000 card_ocr=0x80ff8000
D (516) sdmmc_cmd: sdmmc_card_init: host_ocr=40ff8000, card_ocr=80ff8000
V (526) sdmmc_cmd: sending cmd slot=1 op=2 arg=0 flags=1630 data=0x0 blklen=0 datalen=0 timeout=1000
V (536) sdmmc_req: make_hw_cmd: opcode=2, rexp=1, crc=1
V (536) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (546) sdmmc_req: process_events: state=SENDING_CMD
V (546) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (556) sdmmc_req: process_events state=IDLE next_state=IDLE
V (556) sdmmc_cmd: cmd response 9200d819 10000002 32333220 7fffff31 err=0x0 state=12
V (566) sdmmc_cmd: sending cmd slot=1 op=3 arg=0 flags=1c30 data=0x0 blklen=0 datalen=0 timeout=1000
V (576) sdmmc_req: make_hw_cmd: opcode=3, rexp=1, crc=1
V (586) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (586) sdmmc_req: process_events: state=SENDING_CMD
V (596) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (596) sdmmc_req: process_events state=IDLE next_state=IDLE
V (606) sdmmc_cmd: cmd response 02600500 00000000 00000000 00000000 err=0x0 state=2
V (616) sdmmc_cmd: sending cmd slot=1 op=9 arg=2600000 flags=1600 data=0x0 blklen=0 datalen=0 timeout=1000
V (626) sdmmc_req: make_hw_cmd: opcode=9, rexp=1, crc=1
V (626) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (636) sdmmc_req: process_events: state=SENDING_CMD
V (636) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (646) sdmmc_req: process_events state=IDLE next_state=IDLE
V (656) sdmmc_cmd: cmd response 16800013 ffffcf80 5b5a83c5 007f0032 err=0x0 state=0
V (656) sdmmc_cmd: sending cmd slot=1 op=7 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (666) sdmmc_req: make_hw_cmd: opcode=7, rexp=1, crc=1
V (676) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (676) sdmmc_req: process_events: state=SENDING_CMD
V (686) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (686) sdmmc_req: process_events state=IDLE next_state=IDLE
V (696) sdmmc_cmd: cmd response 00000700 00000000 00000000 00000000 err=0x0 state=3
V (706) sdmmc_cmd: sending cmd slot=1 op=16 arg=200 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (716) sdmmc_req: make_hw_cmd: opcode=16, rexp=1, crc=1
V (716) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (726) sdmmc_req: process_events: state=SENDING_CMD
V (726) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (736) sdmmc_req: process_events state=IDLE next_state=IDLE
V (746) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (746) sdmmc_cmd: sending cmd slot=1 op=55 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (756) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (766) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (766) sdmmc_req: process_events: state=SENDING_CMD
V (776) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (786) sdmmc_req: process_events state=IDLE next_state=IDLE
V (786) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (796) sdmmc_cmd: sending cmd slot=1 op=51 arg=0 flags=1c50 data=0x3ffbc804 blklen=8 datalen=8 timeout=1000
V (806) sdmmc_req: make_hw_cmd: opcode=51, rexp=1, crc=1
V (806) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=8
V (816) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (826) sdmmc_req: process_events: state=SENDING_CMD
V (826) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (836) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (846) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (846) sdmmc_req: process_events: state=SENDIND_DATA
V (856) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (856) sdmmc_req: process_events state=IDLE next_state=IDLE
V (866) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
D (876) sdmmc_cmd: switching to 4-bit bus mode
V (876) sdmmc_cmd: sending cmd slot=1 op=55 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (886) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (896) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (896) sdmmc_req: process_events: state=SENDING_CMD
V (906) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (906) sdmmc_req: process_events state=IDLE next_state=IDLE
V (916) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (926) sdmmc_cmd: sending cmd slot=1 op=6 arg=2 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (936) sdmmc_req: make_hw_cmd: opcode=6, rexp=1, crc=1
V (936) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (946) sdmmc_req: process_events: state=SENDING_CMD
V (946) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (956) sdmmc_req: process_events state=IDLE next_state=IDLE
V (956) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
D (966) sdmmc_periph: slot=1 width=4
V (966) sdmmc_cmd: sending cmd slot=1 op=12 arg=0 flags=1d00 data=0x0 blklen=0 datalen=0 timeout=1000
V (976) sdmmc_req: make_hw_cmd: opcode=12, rexp=1, crc=1
V (986) sdmmc_req: sdmmc_handle_event: evt 00000008 00000000
V (996) sdmmc_req: process_events: state=SENDING_CMD
V (996) sdmmc_req: process_events state=SENDING_CMD next_state=SENDING_CMD
V (1006) sdmmc_req: sdmmc_handle_event: evt 00000100 00000000
V (1006) sdmmc_req: process_events: state=SENDING_CMD
V (1016) sdmmc_req: process_events state=SENDING_CMD next_state=SENDING_CMD
V (1026) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1026) sdmmc_req: process_events: state=SENDING_CMD
V (1036) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1036) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1046) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (1056) sdmmc_cmd: sending cmd slot=1 op=13 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1066) sdmmc_req: make_hw_cmd: opcode=13, rexp=1, crc=1
V (1066) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1076) sdmmc_req: process_events: state=SENDING_CMD
V (1076) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1086) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1086) sdmmc_cmd: cmd response 00400900 00000000 00000000 00000000 err=0x0 state=4
D (1096) sdmmc_cmd: switching to DS bus mode
D (1106) sdmmc_periph: slot=1 div=1 freq=20000kHz
V (1106) sdmmc_cmd: sending cmd slot=1 op=55 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1116) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (1126) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1126) sdmmc_req: process_events: state=SENDING_CMD
V (1136) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1136) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1146) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (1156) sdmmc_cmd: sending cmd slot=1 op=51 arg=0 flags=1c50 data=0x3ffbc804 blklen=8 datalen=8 timeout=1000
V (1166) sdmmc_req: make_hw_cmd: opcode=51, rexp=1, crc=1
V (1166) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=8
V (1176) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1176) sdmmc_req: process_events: state=SENDING_CMD
V (1186) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (1196) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (1196) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (1206) sdmmc_req: process_events: state=SENDIND_DATA
V (1216) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (1216) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1226) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
D (1236) vfs_fat_sdmmc: using pdrv=0
V (1236) sdmmc_cmd: sending cmd slot=1 op=17 arg=0 flags=1c50 data=0x3ffc06ec blklen=512 datalen=512 timeout=1000
V (1246) sdmmc_req: make_hw_cmd: opcode=17, rexp=1, crc=1
V (1246) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=512
V (1256) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1266) sdmmc_req: process_events: state=SENDING_CMD
V (1266) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (1276) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (1286) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (1286) sdmmc_req: process_events: state=SENDIND_DATA
V (1296) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (1296) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1306) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (1316) sdmmc_cmd: sending cmd slot=1 op=13 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1326) sdmmc_req: make_hw_cmd: opcode=13, rexp=1, crc=1
V (1326) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1336) sdmmc_req: process_events: state=SENDING_CMD
V (1336) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1346) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1356) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (1356) sdmmc_cmd: sending cmd slot=1 op=17 arg=200000 flags=1c50 data=0x3ffc06ec blklen=512 datalen=512 timeout=1000
V (1366) sdmmc_req: make_hw_cmd: opcode=17, rexp=1, crc=1
V (1376) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=512
V (1386) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1386) sdmmc_req: process_events: state=SENDING_CMD
V (1396) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (1396) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (1406) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (1416) sdmmc_req: process_events: state=SENDIND_DATA
V (1416) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (1426) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1426) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (1436) sdmmc_cmd: sending cmd slot=1 op=13 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1446) sdmmc_req: make_hw_cmd: opcode=13, rexp=1, crc=1
V (1456) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1456) sdmmc_req: process_events: state=SENDING_CMD
V (1466) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1466) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1476) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
Name: 1232 
Type: SDSC
Speed: default speed
Size: 1932MB
CSD: ver=0, sector_size=512, capacity=3956736 read_bl_len=10
SCR: sd_spec=2, bus_width=5
D (3496) button_task: button_task started.
D (3496) rmt: Rmt Tx Channel 0|Gpio 32|Sclk_Hz 80000000|Div 8|Carrier_Hz 10000|Duty 50
 (3496) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (3496) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (3506) intr_alloc: Connected src 47 to int 17 (cpu 0)
;32mI (3496) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
D (3516) tcpip_adapter: check: local, if=2 fn=0x40103cc0
Gfast2 commented 6 years ago

I'm using a Sparkfun Thing as development board. After Initializing the SD card file system, I've tried to access it in my sd_card task, which don't have anyproblem to I/O file, rename file what so ever.

No matter if I comment out or not the "sd_card" task, I still can't let webserver task I/O the file system. I even tried to access sd card file system at the beginning of my webserver task with no luck. Then I tried to play around use different core to pin the webserver task, I think perhaps is the problem of the file system hook is protected and let it only accessable from on single core, still have no luck.

igrr commented 6 years ago

Thanks, that log is very illuminating.

Could you please try the following: in components/driver/sdmmc_transaction.c, around line 55, remove "| SDMMC_INTMASK_SBE" from the definition of SDMMC_DATA_ERR_MASK. Then try running the application again.

Edit: also in components/driver/sdmmc_host.c, around line 273, remove "SDMMC_INTMASK_SBE | ".

On Tue, Nov 7, 2017 at 7:53 PM, Su notifications@github.com wrote:

I'm using a Sparkfun Thing as development board. After Initializing the SD card file system, I've tried to access it in my sd_card task, which don't have anyproblem to I/O file, rename file what so ever.

No matter if I comment out or not the "sd_card" task, I still can't let webserver task I/O the file system. I even tried to access sd card file system at the beginning of my webserver task with no luck. Then I tried to play around use different core to pin the webserver task, I think perhaps is the problem of the file system hook is protected and let it only accessable from on single core, still have no luck.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/espressif/esp-idf/issues/1237#issuecomment-342460099, or mute the thread https://github.com/notifications/unsubscribe-auth/AEJcehRHMDn40B1QU55roV_yRapNnMpMks5s0ESwgaJpZM4QUoiw .

Gfast2 commented 6 years ago

Hi @igrr ,

W (9616) webserver: Now open my new ESP32 index page
V (9626) vfs_fat: vfs_fat_open: path="/index.html", flags=0, mode=1b6
V (9636) sdmmc_cmd: sending cmd slot=1 op=17 arg=233000 flags=1c50 data=0x3ffc06ec blklen=512 datalen=512 timeout=1000
V (9636) GPS: Sentence - MINMEA_SENTENCE_GSV
V (9656) sdmmc_req: make_hw_cmd: opcode=17, rexp=1, crc=1
V (9666) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=512
V (9676) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (9666) GPS: Sentence - MINMEA_SENTENCE_GLL
V (9696) sdmmc_req: process_events: state=SENDING_CMD
V (9716) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (9736) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
D (9736) rmt: RMT INTR : TX END
D (9796) rmt: RMT INTR : TX END
D (9856) rmt: RMT INTR : TX END
D (9916) rmt: RMT INTR : TX END
D (9966) rmt: RMT INTR : TX END
D (10026) rmt: RMT INTR : TX END
D (10086) rmt: RMT INTR : TX END
D (10146) rmt: RMT INTR : TX END
D (10206) rmt: RMT INTR : TX END
V (10256) GPS: Sentence - MINMEA_SENTENCE_RMC
V (10256) GPS: time: 12:27:31 2017-11-7
D (10266) rmt: RMT INTR : TX END
V (10276) GPS: Sentence - MINMEA_SENTENCE_VTG
V (10316) GPS: Sentence - MINMEA_SENTENCE_GGA
D (10336) rmt: RMT INTR : TX END
V (10366) GPS: Sentence - MINMEA_SENTENCE_GSA
D (10406) rmt: RMT INTR : TX END
V (10436) GPS: Sentence - MINMEA_SENTENCE_GSV
D (10466) rmt: RMT INTR : TX END
V (10496) GPS: Sentence - MINMEA_SENTENCE_GSV
D (10526) rmt: RMT INTR : TX END
V (10566) GPS: Sentence - MINMEA_SENTENCE_GSV
D (105D (10596) rmt: RMT INTR : TX END
96) phy_common: phy_mii_check_link_status(DOWN)
I (10596) emac: eth link_down!!!
D (10606) event: SYSTEM_EVENT_ETH_DISCONNECETED
V (10606) event: enter default callback
D (10616) tcpip_adapter: check: local, if=2 fn=0x401036f4
0x401036f4: tcpip_adapter_down_api at /home/gfast2/esp/esp-idf/components/tcpip_adapter/./tcpip_adapter_lwip.c:1077

D (10616) tcpip_adapter: if2 start ip lost tmr: enter
D (10626) tcpip_adapter: if2 start ip lost tmr: only sta support ip lost timer
D (10636) tcpip_adapter: call api in lwip: ret=0x0, give sem
D (10646) tcpip_adapter: check: remote, if=2 fn=0x401036f4
0x401036f4: tcpip_adapter_down_api at /home/gfast2/esp/esp-idf/components/tcpip_adapter/./tcpip_adapter_lwip.c:1077

V (10656) event: exit default callback
V (10636) GPS: Sentence - MINMEA_SENTENCE_GSV
V (10666) GPS: Sentence - MINMEA_SENTENCE_GLL
D (10706) rmt: RMT INTR : TX END
E (10736) sdmmc_req: sdmmc_host_wait_for_event returned 0x107
D (10736) sdmmc_cmd: sdmmc_req_run returned 0x107
E (10756) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x107
E (10776) diskio_sdmmc: sdmmc_read_blocks failed (263)
D (10776) vfs_fat: vfs_fat_open: fresult=1
E (10796) webserver: Failed to open file for reading
E (10796) webserver: error is 5
Guru Meditation Error of type IllegalInstruction occurred on core  0. Exception was unhandled.
Register dump:
PC      : 0x400e8951  PS      : 0x00060130  A0      : 0x00000000  A1      : 0x3ffdf130  
0x400e8951: mongooseTask at /home/gfast2/workspace/ioc-110-ethernet/main/./webserver.c:308 (discriminator 1)

A2      : 0x3f4070f8  A3      : 0x00002a2c  A4      : 0x00000000  A5      : 0x00000000  
A6      : 0x00000000  A7      : 0x00000000  A8      : 0x800e8951  A9      : 0x3ffdf0e0  
A10     : 0x400fafb0  A11     : 0x3ffb28e4  A12     : 0x3f4072b8  A13     : 0x0000001f  
0x400fafb0: vprintf at /Users/ivan/e/newlib_xtensa-2.2.0-bin/newlib_xtensa-2.2.0/xtensa-esp32-elf/newlib/libc/stdio/../../../.././newlib/libc/stdio/vprintf.c:35

A14     : 0x00000001  A15     : 0x00000005  SAR     : 0x00000004  EXCCAUSE: 0x00000000  
EXCVADDR: 0x00000000  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xfffffffd  

Backtrace: 0x400e8951:0x3ffdf130 0x7ffffffd:0x3ffdf210
0x400e8951: mongooseTask at /home/gfast2/workspace/ioc-110-ethernet/main/./webserver.c:308 (discriminator 1)

CPU halted.
Gfast2 commented 6 years ago

Hi @igrr , up above is where the program stopped. The following is what it said at the beginning:

MONITOR
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x3f (SPI_FAST_FLASH_BOOT)
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x3f (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:5552
ho 0 tail 12 room 4
load:0x40078000,len:0
load:0x40078000,len:12532
entry 0x40078f84
I (30) boot: ESP-IDF v3.0-dev-1028-g2c95a77-dirty 2nd stage bootloader
I (30) boot: compile time 13:26:19
I (42) boot: Enabling RNG early entropy source...
I (42) boot: SPI Speed      : 40MHz
I (42) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (49) boot: Partition Table:
I (52) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (67) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (75) boot:  2 factory          factory app      00 00 00010000 00100000
I (82) boot:  3 storage          Unknown data     01 82 00110000 000f0000
I (90) boot: End of partition table
I (94) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x15ba0 ( 88992) map
I (120) esp_image: segment 1: paddr=0x00025bc8 vaddr=0x3ffb0000 size=0x024a0 (  9376) load
I (122) esp_image: segment 2: paddr=0x00028070 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/gfast2/esp/esp-idf/components/freertos/./xtensa_vectors.S:1685

I (127) esp_image: segment 3: paddr=0x00028478 vaddr=0x40080400 size=0x07b98 ( 31640) load
I (143) esp_image: segment 4: paddr=0x00030018 vaddr=0x400d0018 size=0x4484c (280652) map
0x400d0018: _stext at ??:?

I (200) esp_image: segment 5: paddr=0x0007486c vaddr=0x40087f98 size=0x02438 (  9272) load
0x40087f98: multi_heap_assert at /home/gfast2/esp/esp-idf/components/heap/./multi_heap_platform.h:55
 (inlined by) multi_heap_realloc_impl at /home/gfast2/esp/esp-idf/components/heap/./multi_heap.c:461

I (202) esp_image: segment 6: paddr=0x00076cac vaddr=0x400c0000 size=0x00000 (     0) load
I (208) boot: Loaded app from partition at offset 0x10000
I (212) boot: Disabling RNG early entropy source...
I (218) cpu_start: Pro cpu up.
I (222) cpu_start: Starting app cpu, entry point is 0x40081054
0x40081054: call_start_cpu1 at /home/gfast2/esp/esp-idf/components/esp32/./cpu_start.c:222

I (0) cpu_start: App cpu up.
I (232) heap_init: Initializing. RAM available for dynamic allocation:
D (239) heap_init: New heap initialised at 0x3ffae6e0
I (244) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
D (250) heap_init: New heap initialised at 0x3ffbbe68
I (255) heap_init: At 3FFBBE68 len 00024198 (144 KiB): DRAM
I (261) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (268) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
D (274) heap_init: New heap initialised at 0x4008a3d0
I (279) heap_init: At 4008A3D0 len 00015C30 (87 KiB): IRAM
I (285) cpu_start: Pro cpu start user code
D (297) clk: RTC_SLOW_CLK calibration value: 3461455
V (8) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (8) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (13) intr_alloc: Connected src 46 to int 2 (cpu 0)
V (19) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (24) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xC0E
D (32) intr_alloc: Connected src 57 to int 3 (cpu 0)
V (38) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (44) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (52) intr_alloc: Connected src 16 to int 9 (cpu 0)
V (57) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (63) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0x40E
D (71) intr_alloc: Connected src 24 to int 12 (cpu 0)
I (76) cpu_start: Starting scheduler on PRO CPU.
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): checking args
V (0) intr_alloc: esp_intr_alloc_intrstatus (cpu 1): Args okay. Resulting flags 0x40E
D (10) intr_alloc: Connected src 25 to int 2 (cpu 1)
I (10) cpu_start: Starting scheduler on APP CPU.
D (126) heap_init: New heap initialised at 0x3ffe0440
D (126) heap_init: New heap initialised at 0x3ffe4350
I (136) eth_example: Initializing SD card
D (136) sdmmc_periph: peripheral version 5342270a, hardware config 03c44c83
V (146) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): checking args
V (156) intr_alloc: esp_intr_alloc_intrstatus (cpu 0): Args okay. Resulting flags 0xE
D (166) intr_alloc: Connected src 37 to int 13 (cpu 0)
D (166) sdmmc_periph: slot=1 div=50 freq=400kHz
D (176) sdmmc_periph: slot=1 width=1
D (176) sdmmc_cmd: sdmmc_card_init
V (176) sdmmc_cmd: sending cmd slot=1 op=0 arg=0 flags=20 data=0x0 blklen=0 datalen=0 timeout=1000
V (186) sdmmc_req: make_hw_cmd: opcode=0, rexp=0, crc=0
V (196) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (196) sdmmc_req: process_events: state=SENDING_CMD
V (206) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (206) sdmmc_req: process_events state=IDLE next_state=IDLE
V (216) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0
V (246) sdmmc_cmd: sending cmd slot=1 op=0 arg=0 flags=20 data=0x0 blklen=0 datalen=0 timeout=1000
V (246) sdmmc_req: make_hw_cmd: opcode=0, rexp=0, crc=0
V (246) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (246) sdmmc_req: process_events: state=SENDING_CMD
V (256) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (266) sdmmc_req: process_events state=IDLE next_state=IDLE
V (266) sdmmc_cmd: cmd response 00000000 00000000 00000000 00000000 err=0x0 state=0
V (296) sdmmc_cmd: sending cmd slot=1 op=8 arg=1aa flags=1c30 data=0x0 blklen=0 datalen=0 timeout=1000
V (296) sdmmc_req: make_hw_cmd: opcode=8, rexp=1, crc=1
V (296) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (296) sdmmc_req: process_events: state=SENDING_CMD
V (306) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (316) sdmmc_req: process_events state=IDLE next_state=IDLE
V (316) sdmmc_cmd: cmd response 000001aa 00000000 00000000 00000000 err=0x0 state=0
D (326) sdmmc_cmd: SDHC/SDXC card
V (326) sdmmc_cmd: sending cmd slot=1 op=55 arg=0 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (336) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (346) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (346) sdmmc_req: process_events: state=SENDING_CMD
V (356) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (356) sdmmc_req: process_events state=IDLE next_state=IDLE
V (366) sdmmc_cmd: cmd response 00000120 00000000 00000000 00000000 err=0x0 state=0
V (376) sdmmc_cmd: sending cmd slot=1 op=41 arg=40ff8000 flags=1030 data=0x0 blklen=0 datalen=0 timeout=1000
V (386) sdmmc_req: make_hw_cmd: opcode=41, rexp=1, crc=0
V (386) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (396) sdmmc_req: process_events: state=SENDING_CMD
V (396) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (406) sdmmc_req: process_events state=IDLE next_state=IDLE
V (416) sdmmc_cmd: cmd response 00ff8000 00000000 00000000 00000000 err=0x0 state=0
V (426) sdmmc_cmd: sending cmd slot=1 op=55 arg=0 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (426) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (436) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (436) sdmmc_req: process_events: state=SENDING_CMD
V (446) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (456) sdmmc_req: process_events state=IDLE next_state=IDLE
V (456) sdmmc_cmd: cmd response 00000120 00000000 00000000 00000000 err=0x0 state=0
V (466) sdmmc_cmd: sending cmd slot=1 op=41 arg=40ff8000 flags=1030 data=0x0 blklen=0 datalen=0 timeout=1000
V (476) sdmmc_req: make_hw_cmd: opcode=41, rexp=1, crc=0
V (476) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (486) sdmmc_req: process_events: state=SENDING_CMD
V (486) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (496) sdmmc_req: process_events state=IDLE next_state=IDLE
V (506) sdmmc_cmd: cmd response 80ff8000 00000000 00000000 00000000 err=0x0 state=0
D (506) sdmmc_cmd: host_ocr=0x40ff8000 card_ocr=0x80ff8000
D (516) sdmmc_cmd: sdmmc_card_init: host_ocr=40ff8000, card_ocr=80ff8000
V (526) sdmmc_cmd: sending cmd slot=1 op=2 arg=0 flags=1630 data=0x0 blklen=0 datalen=0 timeout=1000
V (536) sdmmc_req: make_hw_cmd: opcode=2, rexp=1, crc=1
V (536) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (546) sdmmc_req: process_events: state=SENDING_CMD
V (546) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (556) sdmmc_req: process_events state=IDLE next_state=IDLE
V (556) sdmmc_cmd: cmd response 9200d819 10000002 32333220 7fffff31 err=0x0 state=12
V (566) sdmmc_cmd: sending cmd slot=1 op=3 arg=0 flags=1c30 data=0x0 blklen=0 datalen=0 timeout=1000
V (576) sdmmc_req: make_hw_cmd: opcode=3, rexp=1, crc=1
V (586) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (586) sdmmc_req: process_events: state=SENDING_CMD
V (596) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (596) sdmmc_req: process_events state=IDLE next_state=IDLE
V (606) sdmmc_cmd: cmd response 02600500 00000000 00000000 00000000 err=0x0 state=2
V (616) sdmmc_cmd: sending cmd slot=1 op=9 arg=2600000 flags=1600 data=0x0 blklen=0 datalen=0 timeout=1000
V (626) sdmmc_req: make_hw_cmd: opcode=9, rexp=1, crc=1
V (626) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (636) sdmmc_req: process_events: state=SENDING_CMD
V (636) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (646) sdmmc_req: process_events state=IDLE next_state=IDLE
V (656) sdmmc_cmd: cmd response 16800013 ffffcf80 5b5a83c5 007f0032 err=0x0 state=0
V (656) sdmmc_cmd: sending cmd slot=1 op=7 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (666) sdmmc_req: make_hw_cmd: opcode=7, rexp=1, crc=1
V (676) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (676) sdmmc_req: process_events: state=SENDING_CMD
V (686) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (686) sdmmc_req: process_events state=IDLE next_state=IDLE
V (696) sdmmc_cmd: cmd response 00000700 00000000 00000000 00000000 err=0x0 state=3
V (706) sdmmc_cmd: sending cmd slot=1 op=16 arg=200 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (716) sdmmc_req: make_hw_cmd: opcode=16, rexp=1, crc=1
V (716) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (726) sdmmc_req: process_events: state=SENDING_CMD
V (726) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (736) sdmmc_req: process_events state=IDLE next_state=IDLE
V (746) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (746) sdmmc_cmd: sending cmd slot=1 op=55 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (756) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (766) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (766) sdmmc_req: process_events: state=SENDING_CMD
V (776) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (786) sdmmc_req: process_events state=IDLE next_state=IDLE
V (786) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (796) sdmmc_cmd: sending cmd slot=1 op=51 arg=0 flags=1c50 data=0x3ffbc804 blklen=8 datalen=8 timeout=1000
V (806) sdmmc_req: make_hw_cmd: opcode=51, rexp=1, crc=1
V (806) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=8
V (816) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (826) sdmmc_req: process_events: state=SENDING_CMD
V (826) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (836) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (846) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (846) sdmmc_req: process_events: state=SENDIND_DATA
V (856) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (856) sdmmc_req: process_events state=IDLE next_state=IDLE
V (866) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
D (876) sdmmc_cmd: switching to 4-bit bus mode
V (876) sdmmc_cmd: sending cmd slot=1 op=55 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (886) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (896) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (896) sdmmc_req: process_events: state=SENDING_CMD
V (906) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (906) sdmmc_req: process_events state=IDLE next_state=IDLE
V (916) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (926) sdmmc_cmd: sending cmd slot=1 op=6 arg=2 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (936) sdmmc_req: make_hw_cmd: opcode=6, rexp=1, crc=1
V (936) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (946) sdmmc_req: process_events: state=SENDING_CMD
V (946) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (956) sdmmc_req: process_events state=IDLE next_state=IDLE
V (956) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
D (966) sdmmc_periph: slot=1 width=4
V (966) sdmmc_cmd: sending cmd slot=1 op=12 arg=0 flags=1d00 data=0x0 blklen=0 datalen=0 timeout=1000
V (976) sdmmc_req: make_hw_cmd: opcode=12, rexp=1, crc=1
V (986) sdmmc_req: sdmmc_handle_event: evt 00000008 00000000
V (996) sdmmc_req: process_events: state=SENDING_CMD
V (996) sdmmc_req: process_events state=SENDING_CMD next_state=SENDING_CMD
V (1006) sdmmc_req: sdmmc_handle_event: evt 00000100 00000000
V (1006) sdmmc_req: process_events: state=SENDING_CMD
V (1016) sdmmc_req: process_events state=SENDING_CMD next_state=SENDING_CMD
V (1026) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1026) sdmmc_req: process_events: state=SENDING_CMD
V (1036) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1036) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1046) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (1056) sdmmc_cmd: sending cmd slot=1 op=13 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1066) sdmmc_req: make_hw_cmd: opcode=13, rexp=1, crc=1
V (1066) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1076) sdmmc_req: process_events: state=SENDING_CMD
V (1076) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1086) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1086) sdmmc_cmd: cmd response 00400900 00000000 00000000 00000000 err=0x0 state=4
D (1096) sdmmc_cmd: switching to DS bus mode
D (1106) sdmmc_periph: slot=1 div=1 freq=20000kHz
V (1106) sdmmc_cmd: sending cmd slot=1 op=55 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1116) sdmmc_req: make_hw_cmd: opcode=55, rexp=1, crc=1
V (1126) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1126) sdmmc_req: process_events: state=SENDING_CMD
V (1136) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1136) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1146) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
V (1156) sdmmc_cmd: sending cmd slot=1 op=51 arg=0 flags=1c50 data=0x3ffbc804 blklen=8 datalen=8 timeout=1000
V (1166) sdmmc_req: make_hw_cmd: opcode=51, rexp=1, crc=1
V (1166) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=8
V (1176) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1176) sdmmc_req: process_events: state=SENDING_CMD
V (1186) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (1196) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (1196) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (1206) sdmmc_req: process_events: state=SENDIND_DATA
V (1216) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (1216) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1226) sdmmc_cmd: cmd response 00000920 00000000 00000000 00000000 err=0x0 state=4
D (1236) vfs_fat_sdmmc: using pdrv=0
V (1236) sdmmc_cmd: sending cmd slot=1 op=17 arg=0 flags=1c50 data=0x3ffc06ec blklen=512 datalen=512 timeout=1000
V (1246) sdmmc_req: make_hw_cmd: opcode=17, rexp=1, crc=1
V (1246) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=512
V (1256) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1266) sdmmc_req: process_events: state=SENDING_CMD
V (1266) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (1276) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (1286) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (1286) sdmmc_req: process_events: state=SENDIND_DATA
V (1296) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (1296) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1306) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (1316) sdmmc_cmd: sending cmd slot=1 op=13 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1326) sdmmc_req: make_hw_cmd: opcode=13, rexp=1, crc=1
V (1326) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1336) sdmmc_req: process_events: state=SENDING_CMD
V (1336) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1346) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1356) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (1356) sdmmc_cmd: sending cmd slot=1 op=17 arg=200000 flags=1c50 data=0x3ffc06ec blklen=512 datalen=512 timeout=1000
V (1366) sdmmc_req: make_hw_cmd: opcode=17, rexp=1, crc=1
V (1376) sdmmc_req: fill 4 desc=0 rem=0 next=1 last=1 sz=512
V (1386) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1386) sdmmc_req: process_events: state=SENDING_CMD
V (1396) sdmmc_req: process_events state=SENDING_CMD next_state=SENDIND_DATA
V (1396) sdmmc_req: process_events state=SENDIND_DATA next_state=SENDIND_DATA
V (1406) sdmmc_req: sdmmc_handle_event: evt 00000008 00000002
V (1416) sdmmc_req: process_events: state=SENDIND_DATA
V (1416) sdmmc_req: process_events state=SENDIND_DATA next_state=IDLE
V (1426) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1426) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
V (1436) sdmmc_cmd: sending cmd slot=1 op=13 arg=2600000 flags=1c00 data=0x0 blklen=0 datalen=0 timeout=1000
V (1446) sdmmc_req: make_hw_cmd: opcode=13, rexp=1, crc=1
V (1456) sdmmc_req: sdmmc_handle_event: evt 00000004 00000000
V (1456) sdmmc_req: process_events: state=SENDING_CMD
V (1466) sdmmc_req: process_events state=SENDING_CMD next_state=IDLE
V (1466) sdmmc_req: process_events state=IDLE next_state=IDLE
V (1476) sdmmc_cmd: cmd response 00000900 00000000 00000000 00000000 err=0x0 state=4
Name: 1232 
Type: SDSC
Speed: default speed
Size: 1932MB
CSD: ver=0, sector_size=512, capacity=3956736 read_bl_len=10
SCR: sd_spec=2, bus_width=5
Gfast2 commented 6 years ago

BTW: I've tried to put the same peace of snippet into other tasks:

say GPIO task. which doesn't have big foot print and other dependencies like the webserver task has. But still got the same effect.

I even put this file accessing snippet into a small task, which is xTaskCreatePinnedToCore() by app_main() and his definition is written in the same unit where the app_main() is defined. And even there I didn't has my luck neither.

So, I've to say, without too much understanding of the trace and some much more straight error indication, debug do becomes ART! 🎨

igrr commented 6 years ago

That "IllegalInstruction" exception likely indicates that one of your task functions ends without calling vTaskDelete(NULL);. In FreeRTOS, task function can not exit.

Regarding the sd card issue, so far i am not able to reproduce this. Do you think you can create some minimal example which reproduces the issue without external hardware, and share such example with me? Thanks.

On Tue, Nov 7, 2017 at 8:43 PM, Su notifications@github.com wrote:

BTW: I've tried to put the same peace of snippet into other tasks:

say GPIO task. which doesn't have big foot print and other dependencies like the webserver task has. But still got the same effect.

I even put this file accessing snippet into a small task, which is xTaskCreatePinnedToCore() by app_main() and his definition is written in the same unit where the app_main() is defined. And even there I didn't has my luck neither.

So, I've to say, without too much understanding of the trace and some much more straight error indication, debug do becomes ART! 🎨

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/espressif/esp-idf/issues/1237#issuecomment-342470991, or mute the thread https://github.com/notifications/unsubscribe-auth/AEJcevjpuPdlg2KxJ_MEC4_Juy-eeC2Bks5s0FBmgaJpZM4QUoiw .

Gfast2 commented 6 years ago

Hi @igrr ,

Thanks for your advice. I will try my best to reproduce this issue in a mini demo (hopefully today later).

And surely I will addressing problem you mentioned about tasks with no vTaskDelete(NULL).

I've checked all tasks. All tasks that do not has a vTaskDelete(NULL) do have a infinit while(1){} loop.

All right. I leave this question where it is right now. And try to reproduce the same issue without the need of extra hardware (except the bareboned SD card, and pull-up/down resistors if needed).

Gfast2 commented 6 years ago

Hi @igrr ,

I've tried to reproduce this issue without extra hardware. SPIFF+a separate task defined in other units, which accessing the fs of the built-in flash. In that example there is no problem. 👍


Today morning I kept on debugging my right now code. Because I've introduce a Hardware ETH PHY (eth_phy/phy_lan8720) and the SD Card holder. Without extra hardware for ESP32 producing my error is harder then I start from where I am.


What I did is: Initialize the SD file system in app_main() and write something in /sdcard/hello.txt and keep on reading this file each time after a new statement is executed in app_main() by call my test_task(), which will open this file, print out what the file contained and terminate it self at last.

What worth to say: I did stop the dhcp and specified a static IP for my ETH.


The result is: Now sometimes the whole process (without initialize the webserver task) worked out correctly to the last (Initialization finish). But I've tried many times. Most of the time, they crashed. I will post the log for both case:

SUCESSEED

MONITOR
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x3f (SPI_FAST_FLASH_BOOT)
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x3f (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:5552
ho 0 tail 12 room 4
load:0x40078000,len:0
load:0x40078000,len:12532
entry 0x40078f84
I (31) boot: ESP-IDF v3.0-dev-1028-g2c95a77-dirty 2nd stage bootloader
I (31) boot: compile time 14:21:17
I (42) boot: Enabling RNG early entropy source...
I (42) boot: SPI Speed      : 40MHz
I (42) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (49) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (67) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (75) boot:  2 factory          factory app      00 00 00010000 00100000
I (82) boot:  3 storage          Unknown data     01 82 00110000 000f0000
I (90) boot: End of partition table
I (94) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1136c ( 70508) map
I (117) esp_image: segment 1: paddr=0x00021394 vaddr=0x3ffb0000 size=0x0227c (  8828) load
I (119) esp_image: segment 2: paddr=0x00023618 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/gfast2/esp/esp-idf/components/freertos/./xtensa_vectors.S:1685

I (124) esp_image: segment 3: paddr=0x00023a20 vaddr=0x40080400 size=0x09dc4 ( 40388) load
I (141) esp_image: segment 4: paddr=0x0002d7ec vaddr=0x400c0000 size=0x00000 (     0) load
I (141) esp_image: segment 5: paddr=0x0002d7f4 vaddr=0x00000000 size=0x0281c ( 10268) 
I (152) esp_image: segment 6: paddr=0x00030018 vaddr=0x400d0018 size=0x34840 (215104) map
0x400d0018: _stext at ??:?

I (203) boot: Loaded app from partition at offset 0x10000
I (203) boot: Disabling RNG early entropy source...
I (203) cpu_start: Pro cpu up.
I (207) cpu_start: Starting app cpu, entry point is 0x4008100c
0x4008100c: call_start_cpu1 at /home/gfast2/esp/esp-idf/components/esp32/./cpu_start.c:222

I (0) cpu_start: App cpu up.
I (217) heap_init: Initializing. RAM available for dynamic allocation:
I (224) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (230) heap_init: At 3FFBBC20 len 000243E0 (144 KiB): DRAM
I (237) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (243) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (249) heap_init: At 4008A1C4 len 00015E3C (87 KiB): IRAM
I (256) cpu_start: Pro cpu start user code
I (49) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (51) APP_MAIN: Initializing SD card
Name: 1232 
Type: SDSC
Speed: default speed
Size: 1932MB
CSD: ver=0, sector_size=512, capacity=3956736 read_bl_len=10
SCR: sd_spec=2, bus_width=5
I (101) APP_MAIN: Opening file
I (141) APP_MAIN: File written
W (141) APP_MAIN: This is test_task
W (141) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (141) APP_MAIN: Now Terminal the test_task
I (2141) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2141) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2141) gpio: GPIO[38]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2151) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2161) gpio: GPIO[33]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
W (3141) APP_MAIN: This is test_task
W (3141) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (3141) APP_MAIN: Now Terminal the test_task
W (4141) APP_MAIN: This is test_task
I (4141) GPS: init UART
W (4141) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (4141) APP_MAIN: Now Terminal the test_task
W (4491) GPS: SET TIME!!!!
W (5151) APP_MAIN: This is test_task
W (5151) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (5151) APP_MAIN: Now Terminal the test_task
I (5151) APP_MAIN: dhcp client stop RESULT: 0
I (5171) emac: mac version 1137a
I (5171) APP_MAIN: ETH interface get inited correctly!!!
I (5171) emac: emac start !!!

I (5171) emac: emac resetting ....
I (5171) emac: emac reset done
I (5181) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (5201) emac: emac start success !!!
I (9201) emac: eth link_up!!!
I (9201) event: eth ip: 172.23.23.30, mask: 255.255.0.0, gw: 172.23.23.1

FAIED

MONITOR
--- idf_monitor on /dev/ttyUSB0 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x3f (SPI_FAST_FLASH_BOOT)
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x3f (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:5552
ho 0 tail 12 room 4
load:0x40078000,len:0
load:0x40078000,len:12532
entry 0x40078f84
I (30) boot: ESP-IDF v3.0-dev-1028-g2c95a77-dirty 2nd stage bootloader
I (30) boot: compile time 14:21:17
I (42) boot: Enabling RNG early entropy source...
I (42) boot: SPI Speed      : 40MHz
I (42) boot: SPI Mode       : DIO
I (45) boot: SPI Flash Size : 4MB
I (49) boot: Partition Table:
I (53) boot: ## Label            Usage          Type ST Offset   Length
I (60) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (67) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (75) boot:  2 factory          factory app      00 00 00010000 00100000
I (82) boot:  3 storage          Unknown data     01 82 00110000 000f0000
I (90) boot: End of partition table
I (94) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x1136c ( 70508) map
I (117) esp_image: segment 1: paddr=0x00021394 vaddr=0x3ffb0000 size=0x0227c (  8828) load
I (119) esp_image: segment 2: paddr=0x00023618 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _iram_start at /home/gfast2/esp/esp-idf/components/freertos/./xtensa_vectors.S:1685

I (124) esp_image: segment 3: paddr=0x00023a20 vaddr=0x40080400 size=0x09dc4 ( 40388) load
I (141) esp_image: segment 4: paddr=0x0002d7ec vaddr=0x400c0000 size=0x00000 (     0) load
I (141) esp_image: segment 5: paddr=0x0002d7f4 vaddr=0x00000000 size=0x0281c ( 10268) 
I (152) esp_image: segment 6: paddr=0x00030018 vaddr=0x400d0018 size=0x34840 (215104) map
0x400d0018: _stext at ??:?

I (203) boot: Loaded app from partition at offset 0x10000
I (203) boot: Disabling RNG early entropy source...
I (203) cpu_start: Pro cpu up.
I (207) cpu_start: Starting app cpu, entry point is 0x4008100c
0x4008100c: call_start_cpu1 at /home/gfast2/esp/esp-idf/components/esp32/./cpu_start.c:222

I (0) cpu_start: App cpu up.
I (217) heap_init: Initializing. RAM available for dynamic allocation:
I (224) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (230) heap_init: At 3FFBBC20 len 000243E0 (144 KiB): DRAM
I (237) heap_init: At 3FFE0440 len 00003BC0 (14 KiB): D/IRAM
I (243) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (249) heap_init: At 4008A1C4 len 00015E3C (87 KiB): IRAM
I (255) cpu_start: Pro cpu start user code
I (49) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (50) APP_MAIN: Initializing SD card
Name: 1232 
Type: SDSC
Speed: default speed
Size: 1932MB
CSD: ver=0, sector_size=512, capacity=3956736 read_bl_len=10
SCR: sd_spec=2, bus_width=5
I (100) APP_MAIN: Opening file
I (140) APP_MAIN: File written
W (140) APP_MAIN: This is test_task
W (140) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (140) APP_MAIN: Now Terminal the test_task
I (2140) gpio: GPIO[36]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2140) gpio: GPIO[37]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2140) gpio: GPIO[38]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2150) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (2160) gpio: GPIO[33]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
W (3140) APP_MAIN: This is test_task
W (3140) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (3140) APP_MAIN: Now Terminal the test_task
W (4140) APP_MAIN: This is test_task
I (4140) GPS: init UART
W (4140) APP_MAIN: Read from file: 'Hello! This is my awesome sd card test on 1232 !'
I (4140) APP_MAIN: Now Terminal the test_task
W (5060) GPS: SET TIME!!!!
W (5150) APP_MAIN: This is test_task
I (5150) APP_MAIN: dhcp client stop RESULT: 0
I (5160) emac: mac version 1137a
I (5160) APP_MAIN: ETH interface get inited correctly!!!
I (5160) emac: emac start !!!

I (5160) emac: emac resetting ....
I (5160) emac: emac reset done
I (5170) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (5190) emac: emac start success !!!
E (6150) sdmmc_req: sdmmc_host_wait_for_event returned 0x107
E (6150) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x107
E (6150) diskio_sdmmc: sdmmc_read_blocks failed (263)
W (6150) APP_MAIN: Read from file: ''
I (6160) APP_MAIN: Now Terminal the test_task
I (9190) emac: eth link_up!!!
I (9190) event: eth ip: 172.23.23.30, mask: 255.255.0.0, gw: 172.23.23.1
igrr commented 6 years ago

Okay, i can do a test with ETH PHY here. Can you upload your project (which has ETH and SD card) somewhere so that we will be testing the same thing? Thanks a lot.

Gfast2 commented 6 years ago

Hi @igrr ,

Then I've to talk with my project leader. If its possible, I will share you a private repo.

Gfast2 commented 6 years ago

I got a simplified version. Can I get your Email addresss? ⚜️

igrr commented 6 years ago

ivan at espressif com.

On Wed, Nov 8, 2017, 22:35 Su notifications@github.com wrote:

I got a simplified version. Can I get your Email addresss? ⚜️

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/espressif/esp-idf/issues/1237#issuecomment-342835651, or mute the thread https://github.com/notifications/unsubscribe-auth/AEJceiHOPqlUBVQC27I1xT1n_dknTJBKks5s0bwzgaJpZM4QUoiw .

Gfast2 commented 6 years ago

I've sent the Email. Happy tunning! 💇‍♂️

Gfast2 commented 6 years ago

Hi ESP-IDF,

Today I still keeping on tuning.

Now I package all ethernet driver init stuff into one task ethinit.c and all sd card driver init stuff into another sd_card.c. After the SD card driver get inited, I wait 2 sec. and then start the init process of ETH interface. After the init of ETH I check the init status, if I got SYSTEM_EVENT_ETH_GOT_IP, then I call test_task to access the sd card fs through spiff. And in this test set, I got the following interesting log:

W (7102) ETHINIT: ETH Got IP now
W (7102) TEST_TASK: This is test_task
W (7112) TEST_TASK: File name to be read is: /sdcard/iaf_config_ioc110.xml
I (7122) TEST_TASK: NOW Read from SD Card:
E (7122) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x109
E (7132) diskio_sdmmc: sdmmc_read_blocks failed (265)
E (7132) TEST_TASK: Failed to open file for reading
I (9102) emac: eth link_down!!!
I (9102) ETHINIT: GOT SYSTEM_EVENT. 22
I (11102) emac: eth link_up!!!
I (11142) ETHINIT: GOT SYSTEM_EVENT. 21
I (11142) event: eth ip: 172.23.23.30, mask: 255.255.0.0, gw: 172.23.23.1
W (11142) ETHINIT: ETH Got IP now
W (11152) TEST_TASK: This is test_task
W (11152) TEST_TASK: File name to be read is: /sdcard/iaf_config_ioc110.xml
I (11162) TEST_TASK: NOW Read from SD Card:
E (12162) sdmmc_req: sdmmc_host_wait_for_event returned 0x107
E (12162) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x107
E (12162) diskio_sdmmc: sdmmc_read_blocks failed (263)
E (12162) TEST_TASK: Failed to open file for reading
I (13102) emac: eth link_down!!!
I (13102) ETHINIT: GOT SYSTEM_EVENT. 22
I (15102) emac: eth link_up!!!
I (15102) ETHINIT: GOT SYSTEM_EVENT. 21
I (15102) event: eth ip: 172.23.23.30, mask: 255.255.0.0, gw: 172.23.23.1
W (15102) ETHINIT: ETH Got IP now
W (15102) TEST_TASK: This is test_task
W (15112) TEST_TASK: File name to be read is: /sdcard/iaf_config_ioc110.xml
I (15122) TEST_TASK: NOW Read from SD Card:
E (16122) sdmmc_req: sdmmc_host_wait_for_event returned 0x107
E (16122) sdmmc_cmd: sdmmc_read_sectors_dma: sdmmc_send_cmd returned 0x107
E (16122) diskio_sdmmc: sdmmc_read_blocks failed (263)
E (16122) TEST_TASK: Failed to open file for reading
igrr commented 6 years ago

Just one thing to check, do you have ETH PHY clock connected to GPIO0? Is there any connection between GPIO0 and GPIO2 on your board (through some resistor, perhaps?).

The first error you receive is 0x109, which is "invalid CRC" error, indicating data corruption on SD card lines. It is possible that high-speed Ethernet signals are coupled to SD card lines, introducing some noise.

Gfast2 commented 6 years ago

Hi @iggr,

It did looks like so. I did bridge the GPIO0 and GPIO2 together. The purpose I can not more remember. Since I'm using a jumper to do the job. I will check this out right now.

Gfast2 commented 6 years ago

BANG! ❗️❗️❗️

It works out of the box! AS IT SHOULD! 💪 🛑 🎈 🍰 I just can't tell how happy right now I am after so many days tweakling around!

(But still a very nice to have experience at last) 👙

P.s: Before I close this issue, I'd prefer to figure out why I spent time to build this jumper that connect GPIO00 and GPIO02.

igrr commented 6 years ago

You have likely added that jumper because sd_card example readme suggests doing so:

https://github.com/espressif/esp-idf/tree/master/examples/storage/sd_card#note-about-gpio2

When you want to upload code to ESP32, GPIO2 needs to be low, otherwise ESP32 won't be able to enter bootloader mode. But with SD card, GPIO2 needs to be pulled up. One easy way to have GPIO2 pulled up and also force it to be low when entering bootloader mode is to connect GPIO2 and GPIO0. But as you have found, if GPIO0 is connected to ETH clock, the clock signal will be connected via jumper to GPIO2, causing issues with SD card communication.

One way around this is to use reset circuit similar to the one found on WROVER-KIT v3 board. This circuit has an extra transistor to pull GPIO2 down when entering bootloader mode. https://dl.espressif.com/dl/schematics/ESP-WROVER-KIT_SCH-3.pdf (the transistor i have mentioned is Q9 in this schematic)

Gfast2 commented 6 years ago

Hi ESP-IDF: According to the README from sd card example and ethernet example. GPIO02 are used for different purpose: For sd card: This pin is Bootstrap pin. It should be connected with GPIO00, in order to let the SD card deactivated during the Flash programming through UART. For Ethernet: This pin is Reference Frequence pin. It will be connected to the 50MHz Quartz from the ethernet PHY board. GPIO00 it self: It is also the pin to let ESP32 go into UART programming mode. Wenn it is pulled-low. ESP32 will enter the programming mode.


So the final effect is: After I init the Ethernet board, the 50MHz will start to toggling the state of GPIO02 which will keep on activate/deactivate SD card. So surelly, it won't be possible to let tasks after the initilization of the ehternet access files in SD card. 🚴

Gfast2 commented 6 years ago

Hi Guys,

I'm back. After another days long struggling with my webserver, Today I suddenly figured out: Why my Mongoose Server just works so bad: It can't play as a normal Websocket Server, that send Websocket Frame reliably!! It's nothing to do with the code. It is the problem of the pullup / pulldown resistors on GPIO0 and GPIO2! (highly suspected!!) 💢

The effect is very frustrating: After I finish upload app, I cut the connection between GPIO0 and GPIO2. Then the ETH will works for a while. If I do a flood ping on its ETH, it will drop more then 10% of the packages. BUT if I continue connect the both GPIO, and avoid to access the SD card, the flood ping won't drop more then 0% packages. The webserver works also very stable. For a really long time, I thought its souly a software problem...

I made some screenshot of my Probes. So I'd very like to know, if the pull-up / pull-down resistor on my board not effective enough according to these photos:

GPIO0 after the Ethernet get inited: gpio0

GPIO2 without SD Card inserted: gpio2_without_sdcard

GPIO2 with SD Card inserted: gpio2_with_sdcard

Gfast2 commented 6 years ago

BTW: I've hook a 4.7K pullup resistor (4.1K in real) on GPIO0 and a 10K (9.2K in real) pullup resistor on GPIO2 as their example suggested respectly.

Wiring-Recipie for GPIO0 Wiring-Recipie for GPIO2

The Voltage between VCC and GND is currently 3.278V, which I believe still good enough. ☁️

Gfast2 commented 6 years ago

Olimex sells right now a "ESP32-Gateway" board, which features SD Card and Ethernet. According to its opensourced design - ESP32-GATEWAY_Rev_B_color.pdf, they use a 2.2K + 220 combination as GPIO2's pull-up resistor: sd_card

And later use even a 10R resistor between GPIO0 and the 50MHz Quartz‼️ 50mhz Should I do the same? Is this the real solution when I'd like to have the Ethernet and the SD Card at the same time?

sauttefk commented 6 years ago

Those 10Ω resistors in series are there to reduce ringing / overshoots on those high frequency signals (impedance matching) https://en.wikipedia.org/wiki/Ringing_(signal) https://en.wikipedia.org/wiki/Impedance_matching http://www.marvintest.com/KnowledgeBase/KBArticle.aspx?ID=196

Gfast2 commented 6 years ago

Hi @sauttefk , My pleasure to talk to you! Do you mean, the 4k7 pullup resistor that in your post about LAN8720 is really proper designed, or may be worth it, if I'd try a smaller one according to the screenshot of the scope?

Thanks for the link! 👍

Gfast2 commented 6 years ago

And I believe I figured out, the 10R resistor is not the "Pull" resistor. And the "R54" is actually the one I'm searching for: r54 But this one is not markt with its value. Is that means, event when after finished the board design, Olimex still need to investigate sometime to tweaking around this resistor with a proper value? It looks like, I'm not alone. ⛽️

sauttefk commented 6 years ago

R54 is not populated. Why are you directly connecting GPIO0 and GPIO2? This won't work. Use some diodes to decouple the signals. Like this:

bildschirmfoto 2017-11-13 um 23 59 26
sauttefk commented 6 years ago

Maybe you check out my PR #1127 Use APLL to generate a 50MHz clock signal for the Ethernet PHY on GPIO17. Advantages:

Gfast2 commented 6 years ago

Hi @sauttefk, I think I have to hange on the solution with a 50MHz Quartz. Because I need the UART1 which will recruite GPIO17 as RX pin. But your board and design is stunning!!! 🛍 I looks like, that today I should spend whole day very possibly tunning the right value of the pull-up resistor.

P.s GPIO2 is used to pull-up the DATA0 of the SD-Card interface. When I in download mode, SD-Card should be deactivated. So the easiest approach should be... as the ESP-IDF SD-Card example descripted: Connect the both pin.

sauttefk commented 6 years ago

@Gfast2

GPIO2 is used to pull-up the DATA0 of the SD-Card interface. When I in download mode, SD-Card should be deactivated. So the easiest approach should be... as the ESP-IDF SD-Card example descripted: Connect the both pin. Use the diodes (as shown above) to decouple GPIO0 and GPIO2. In this way GPIO0 and GPIO2 during bootstrapping but otherwise don't interfere.

sauttefk commented 6 years ago

@Gfast2

I think I have to hange on the solution with a 50MHz Quartz. Because I need the UART1 which will recruite GPIO17 as RX pin.

No One of the nice features of the ESP32: You can route most of the signals (exept for some high-speed signals such as SD-Card or EMAC interface, that can only be used as direct-IO in the IO_MUX) through the GPIO-Matrix to any physical IO pin. For sure this work for all the UARTs (see chapter 4 in the Technical Reference Manual) Referring to table 17: Signal 17 U1TXD and U1RXD, Signal 198 U2TXD and U2RXD

Gfast2 commented 6 years ago

Hi @sauttefk ,

Super big thanks for your declaration about the _IO_MUX_. I spend nearlly an hour trying to understand this table. Because of the lack of deep enough knowledge in electronic. I'm afraid as far as I can understand, I can only tell that I can reroute the UART interface almost to anywhere. BUT I STILL CAN'T TELL: Can I use GPIO16 as the 50MHz wave generater? Right now I'm using that one as the physical power-enable pin for 50MHz extern Quartz. 💭

sauttefk commented 6 years ago

@Gfast2 : Please refer to the description I updated here: https://github.com/espressif/esp-idf/tree/master/examples/ethernet/ethernet#phy-clock-wiring

The inverted clock signal EMAC_CLK_180 (GPIO17)was found working best with a LAN8720 PHY.

Which means GPIO0 and GPIO2 had issues / were instable. Maybe an inverter (such as 74VHC1G14) will do the job, but this is only an idea.

GPIO0 would have been my prime choice as it would not use additional IO pins. But the signal is normally too distorted because of all the additional capacitive load due to all the components connected to it. Maybe an inverter between GPIO0 and the clock input of the Ethernet PHY would help here. Bootstrap circuit (RTS) ──┬──┤◁ Diode──┤GPIO0├───┤33Ω├──┤Inverter├──┤33Ω├──┤PHY ClockIn ␠ ␠ ␠ ␠ ␠ ␠ ␠ ␠ ␠ ␠ ␠ └──┤◁ Diode──┤GPIO2

Gfast2 commented 6 years ago

OK, I'll do try your advice later if I do get a breath out of my project time plan. BTW: According to the PR you mentioned above, it looks like it still need to do small Interfacing job before that get merged into the master. If that still take a while, I will try out your commit through cherry-picked commit


I soldered a 8.2K between vcc and GPIO0 as extra pull-up, and a 5.5K between vcc and GPIO2 for the same perpose. I found the vcc perhapse need some decoupling job:

(Violet is GPIO0, Blue is vcc) 1


Now I can access SD-Card filesystem after initialize the ETH without any (hardware) problem any more.

So thanks again for your guys come to help me out. I will leave this open for a while, and perhapse someone would like to leave here some extra comments. 👼

sauttefk commented 6 years ago

I soldered a 8.2K between vcc and GPIO0 as extra pull-up, and a 5.5K between vcc and GPIO2 for the same perpose. I found the vcc perhapse need some decoupling job:

@Gfast2 : This will NOT work stable. Try the diodes circuitry (the screenshot from the schematic of the ESP32-EVB RevB from Olimex I posted above)

Gfast2 commented 6 years ago

Hi @sauttefk ,

Perhapse I just enter the lobby room filled with a bunch of really SENIOR Electronic Engineers and Software Developers. So many things for you are as clear as looking through a glass of clear water. For me, for instance, I can't not really get the idea "Why it won't work stable" and "How to wire my right now circuit as the Olemix doese."

I'm pretty said about this, too, from my deep heart. But this is also the reason why I'm here!

What ever, I will try it with my best effort later. Thanks @sauttefk

igrr commented 6 years ago

Closing this, as this issue tracker is not the right place for hardware design discussion. Please use esp32.com forum instead.