Description
Hardware:
Board: ESP32 DEVKITV1
Core Installation/update date: 25/apr/2018
IDE name: Arduino IDE/IDF component
Flash Frequency: 80Mhz
Upload Speed: 115200
Description:
micros() returns strange values when using arduino-esp32 as component of esp-idf,
millis() returns values higher when using arduino-esp32 as component of esp-idf, then values using simply from Arduino IDE
Primarily I used Arduino IDE to code MCU, I had simple code to measure performance of some calculations, used method micros() to calculate difference. After some playing and toying I decided to try esp-idf to take advantage of multiple cores and eliminate constant arduino loop, but in result I realised that there are some troubles with my ported code, I can't rely on micros(), and also millis() returns higher values, seems that esp_timer_get_time return more adequate results, but I am not sure.
May be I should try another robust way to calculate diff in esp-idf?
But what will be with Arduino libs which uses standard millis/micros, for example method delayMicroseconds() uses micros() internally, I think it should be rewritten to use cycles instead for performance(but this method still gives me wrong results)
Sketch:
as component of esp-idf:
unsigned long prevcc;
unsigned long prevus;
unsigned long prevms;
uint64_t preveus;
unsigned long mm_micros() {
unsigned long ct = cycles();
unsigned long ut = micros();
unsigned long mt = millis();
uint64_t eus = esp_timer_get_time();
if (mt - prevms < 1000) {
ESP_LOGW("TIME API", "timing@cpu%u %lu(%lu(%lu)), %lu/%llu(%lu/%llu), in millis: %lu(%lu)", xPortGetCoreID(), ct, ct - prevcc, ECC_2_MICROS(ct - prevcc), ut, eus, ut - prevus, eus - preveus, mt, mt - prevms);
}
prevus = ut;
prevms = mt;
prevcc = ct;
preveus = eus;
return ut;
}as Arduino IDE component:
uint32_t prevcc;
unsigned long prevus;
unsigned long prevms;
uint64_t preveus;
unsigned long mm_micros() {
uint32_t cc = ESP.getCycleCount();
unsigned long ut = micros();
unsigned long mt = millis();
uint64_t eus = esp_timer_get_time();
if (mt - prevms < 1000) {
Serial.printf("timing@cpu%u %u(%u(%u)) %lu/%llu(%lu/%llu), in millis: %lu(%lu)\n", xPortGetCoreID(), cc, cc - prevcc, (cc - prevcc) / 240, ut, eus, ut - prevus, eus - preveus, mt, mt - prevms);
}
prevus = ut;
prevms = mt;
preveus = eus;
prevcc = cc;
return ut;
}Debug Messages:
as component of esp-idf:
W (8037534) TIME API: timing@cpu1 1044785094(4256331244(17734713)), 3207683041/7705431254(17734714/3921), in millis: 8037321(4)
W (8038230) TIME API: timing@cpu0 1129179091(84393997(351641)), 3208034678/7706101621(351637/670367), in millis: 8038017(696)
W (8044936) TIME API: timing@cpu1 1514182076(376265(1567)), 3209638855/7712489794(1561/2333), in millis: 8044723(2)
W (8045626) TIME API: timing@cpu0 1596910672(82728596(344702)), 3209983564/7713154637(344709W (8045629)
W (8052328) TIME API: timing@cpu1 1981228712(67886(282)), 3211584883/7719566021(277/277), in millis: 8052115(1)
W (8053022) TIME API: timing@cpu1 2027760812(46532100(193883)), 3211778775/7720230577(193892/664556), in millis: 8052809(694)
W (8059723) TIME API: timing@cpu1 2432887494(78965(329)), 3213466795/7726657220(323/323), in millis: 8059510(0)
W (8060417) TIME API: timing@cpu1 2481210626(48323132(201346)), 3213668147/7727306043(201352/648823), in millis: 8060204(694)
as Arduino IDE component:
timing@cpu1 634691767(482970(2012)) 2644549/2615061(2011/2011), in millis: 2614(2)
timing@cpu1 797158638(162466871(676945)) 3321495/3292006(676946/676945), in millis: 3291(677)
timing@cpu1 2074474690(322389(1343)) 8643645/8614156(1342/1341), in millis: 8613(1)
timing@cpu1 2236918638(162443948(676849)) 9320495/9291006(676850/676850), in millis: 9290(677)
timing@cpu1 3514217081(63517(264)) 14642572/14613083(264/263), in millis: 14612(0)
timing@cpu1 3676678638(162461557(676923)) 15319495/15290006(676923/676923), in millis: 15289(677)
timing@cpu1 659261895(77451(322)) 20642622/20613133(321/321), in millis: 20612(0)
timing@cpu1 821711342(162449447(676872)) 21319495/21290006(676873/676873), in millis: 21289(677)
timing@cpu1 2099265873(81147(338)) 26642639/26613150(337/336), in millis: 26612(0)
timing@cpu1 2261711342(162445469(676856)) 27319495/27290006(676856/676856), in millis: 27289(677)
timing@cpu1 3539240286(55848(232)) 32642532/32613043(231/231), in millis: 32612(0)
timing@cpu1 3701711342(162471056(676962)) 33319495/33290006(676963/676963), in millis: 33289(677)
As you can see I have 20ms penalty using millis() method, which isn't seen If I use diff provided from values of methods esp_timer_get_time.
micros() are reasonable on small range, but not always!