[TW#24153] HW timer stops 2ms every 100ms #240

ghost · 2018-06-25T17:51:17Z

Environment

Development Kit: esp12e + white adapter
IDF version (git rev-parse --short HEAD to get the commit id.):
305a338
Development Env: Make
Operating System: Windows/msys2
Power Supply: USB

Problem Description

I'm trying to play tunes using the hw timer (hw_timer.h)
This work, but it seems every 100ms the interrupt/timer stops for about 2ms.
I think some other task is interfering, but not sure how to find out which task.
This happens even in a minimal example.

Expected Behavior

hw timer keeps working continuously.

Actual Behavior

Every 100ms there's a 2ms of no interrupts.

Steps to repropduce

Compile/run example code
Connect speaker to defined speaker pin, it sounds bad.
Connect logic analyzer/scope to same pin, instead of speaker. You can see the gaps.

Code to reproduce this issue

NOTE: Wifi is enabled, cause removing all wifi code seems to cause a crash shortly after booting.

#include <stddef.h>
#include <stdio.h>
#include <stdbool.h>
#include <stdint.h>
#include <string.h>
#include <stdlib.h>
#include <ctype.h>

#include "esp_sta.h"
#include "esp_system.h"
#include "esp_wifi.h"
#include "esp_attr.h"

#include "freertos/FreeRTOS.h"
#include "freertos/task.h"

#include "user_config.h"

#include "driver/uart.h"
#include "driver/gpio.h"
#include "driver/hw_timer.h"

#define NOTE_C6  1047
#define NOTE_CS6 1109
#define NOTE_D6  1175
#define NOTE_DS6 1245
#define NOTE_E6  1319
#define NOTE_F6  1397
#define NOTE_FS6 1480
#define NOTE_G6  1568
#define NOTE_GS6 1661
#define NOTE_A6  1760
#define NOTE_AS6 1865
#define NOTE_B6  1976
#define NOTE_C7  2093
#define NOTE_CS7 2217
#define NOTE_D7  2349
#define NOTE_DS7 2489
#define NOTE_E7  2637
#define NOTE_F7  2794
#define NOTE_FS7 2960
#define NOTE_G7  3136
#define NOTE_GS7 3322
#define NOTE_A7  3520
#define NOTE_AS7 3729
#define NOTE_B7  3951

#define QUARTER 4.0
#define THIRD 3.0

#define SPEAKER_PIN 13

//Mario main theme melody
int marioMelody[] = {
  NOTE_E7, NOTE_E7, 0, NOTE_E7,
  0, NOTE_C7, NOTE_E7, 0,
  NOTE_G7, 0, 0, 0,
  NOTE_G6, 0, 0, 0,

  NOTE_C7, 0, 0, NOTE_G6,
  0, 0, NOTE_E6, 0,
  0, NOTE_A6, 0, NOTE_B6,
  0, NOTE_AS6, NOTE_A6, 0,

  NOTE_G6, NOTE_E7, NOTE_G7,
  NOTE_A7, 0, NOTE_F7, NOTE_G7,
  0, NOTE_E7, 0, NOTE_C7,
  NOTE_D7, NOTE_B6, 0, 0,

  NOTE_C7, 0, 0, NOTE_G6,
  0, 0, NOTE_E6, 0,
  0, NOTE_A6, 0, NOTE_B6,
  0, NOTE_AS6, NOTE_A6, 0,

  NOTE_G6, NOTE_E7, NOTE_G7,
  NOTE_A7, 0, NOTE_F7, NOTE_G7,
  0, NOTE_E7, 0, NOTE_C7,
  NOTE_D7, NOTE_B6, 0, 0
};

//Mario main them tempo
int marioNoteDurations[] = {
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  THIRD, THIRD, THIRD,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  THIRD, THIRD, THIRD,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
};

void gpio_config(GPIO_ConfigTypeDef* pGPIOConfig);

static xTaskHandle tune_task_handle;

static bool state = false;

IRAM_ATTR void toneISR(void) {
  state = !state;
  GPIO_OUTPUT_SET(SPEAKER_PIN, state);
}

void playTune(const int noteMs, const int size, const int melody[], const int noteDurations[]) {

  hw_timer_init();
  hw_timer_set_func(toneISR);

  for (int thisNote = 0; thisNote < size; thisNote++) {

    int noteDurationMs = (int)(noteMs / noteDurations[thisNote]);
    if (melody[thisNote] != 0) {
      hw_timer_arm(((1000 * 1000) / melody[thisNote])/2, true);
    }

    vTaskDelay( noteDurationMs / portTICK_PERIOD_MS );
    hw_timer_disarm();
    GPIO_OUTPUT_SET(SPEAKER_PIN, false);

    int pauseBetweenNotesMs = noteDurationMs * 0.30;
    vTaskDelay( pauseBetweenNotesMs / portTICK_PERIOD_MS );
  }
}

static void tune_task_thread(void* pvParameters) {

    GPIO_ConfigTypeDef io_out_conf;

    io_out_conf.GPIO_IntrType = GPIO_PIN_INTR_DISABLE;
    io_out_conf.GPIO_Mode = GPIO_Mode_Output;
    io_out_conf.GPIO_Pin = BIT(SPEAKER_PIN);
    io_out_conf.GPIO_Pullup = GPIO_PullUp_DIS;
    gpio_config(&io_out_conf);

    GPIO_OUTPUT_SET(SPEAKER_PIN, false);

    playTune(600, sizeof(marioMelody) / sizeof(int), marioMelody, marioNoteDurations);

    vTaskDelete(NULL);
    return;
}

uint32_t user_rf_cal_sector_set(void) {
    flash_size_map size_map = system_get_flash_size_map();
    uint32_t rf_cal_sec = 0;

    switch (size_map) {
        case FLASH_SIZE_4M_MAP_256_256:
            rf_cal_sec = 128 - 5;
            break;

        case FLASH_SIZE_8M_MAP_512_512:
            rf_cal_sec = 256 - 5;
            break;

        case FLASH_SIZE_16M_MAP_512_512:
        case FLASH_SIZE_16M_MAP_1024_1024:
            rf_cal_sec = 512 - 5;
            break;

        case FLASH_SIZE_32M_MAP_512_512:
        case FLASH_SIZE_32M_MAP_1024_1024:
            rf_cal_sec = 1024 - 5;
            break;

        case FLASH_SIZE_64M_MAP_1024_1024:
            rf_cal_sec = 2048 - 5;
            break;

        case FLASH_SIZE_128M_MAP_1024_1024:
            rf_cal_sec = 4096 - 5;
            break;

        default:
            rf_cal_sec = 0;
            break;
    }

    return rf_cal_sec;
}

void wifi_event_handler_cb(System_Event_t* event) {
    if (event == NULL) {
        return;
    }

    switch (event->event_id) {
        case EVENT_STAMODE_GOT_IP:
            printf("sta got ip ,create task and free heap size is %d\n", system_get_free_heap_size());
            break;

        case EVENT_STAMODE_CONNECTED:
            printf("sta connected\n");
            break;

        case EVENT_STAMODE_DISCONNECTED:
            wifi_station_connect();
            break;

        default:
            break;
    }
}

void user_init(void) {

    UART_SetBaudrate(UART0, BIT_RATE_74880);

	printf("SDK version:%s rom %d\n", system_get_sdk_version(), system_upgrade_userbin_check());

    wifi_set_opmode(STATION_MODE);

    struct station_config config;
    bzero(&config, sizeof(struct station_config));
    sprintf((char*)config.ssid, SSID);
    sprintf((char*)config.password, PASSWORD);
    wifi_station_set_config(&config);

    wifi_set_event_handler_cb(wifi_event_handler_cb);

    xTaskCreate(tune_task_thread, "tune_task_thread", 2048, NULL, 7, &tune_task_handle);
}

Debug Logs

Sigrok capture showing the 'gaps', each has roughly 102 ms inbetween:

Note: Click for full size, it's the tiny gaps in this picture. The big gaps are between notes and intended.

Sigrok capture showing one gap, it's size is roughly around 2ms

Sigrok capture file:
sample.zip

Other items if possible

sdkconfig file (attach the sdkconfig file from your project folder)
sdkconfig.txt
elf file in the build folder (note this may contain all the code details and symbols of your project.)
my_first_project.zip

The text was updated successfully, but these errors were encountered:

ghost · 2018-07-04T16:27:29Z

Is there anything else I can provide to make this get more attention? :)

dudanov · 2018-07-05T05:00:11Z

The problem is that you use the vTaskDelay function, which allows the scheduler to transfer control to another task, such as a wireless or network stack. Use critical sections (in preemptive multitasking) and delays based on simple program cycles. PWM in ESP is non-hardware! Howewer, the best solution, in my opinion, is to transfer the logic from the task to the toneISR interrupt handler.
P.S.: Don't forget about volatile qualifier.

ghost · 2018-07-05T06:08:27Z

The vTaskDelay doesn't pause the actual generating of the note.
The note is generated by the 'hw_timer_..' functions in combination with the toneISR interrupt handler.
This uses a built in hardware timer which triggers an interrupt rapidly.
The handling of this interrupt may be interrupted by other interrupts, or possibly by other tasks (not sure about that?). But it's surprising if other tasks run for 2ms continuously, which is a very long time in CPU cycles.
The way the tone is created is basically the same way that for example the Arduino ESP8266 (based on non-rtos esp8266 sdk) creates a tone. It's surprising if that would not be possible in the RTOS version of the SDK?

Isn't volatile only needed on variables handled both inside and outside an ISR?

Thanks!

ghost · 2018-07-12T20:07:20Z

Just an update, still the same with ESP8266_RTOS_SDK revision 7005cee,
and https://dl.espressif.com/dl/xtensa-lx106-elf-win32-1.22.0-88-gde0bdc1-4.8.5.tar.gz on msys2. :)

Updated source for the new SDK:

#include <stddef.h>
#include <stdio.h>
#include <stdbool.h>
#include <stdint.h>
#include <string.h>
#include <stdlib.h>
#include <ctype.h>

#include "esp_system.h"
#include "esp_wifi.h"
#include "esp_event_loop.h"
#include "esp_log.h"
#include "esp_attr.h"
#include "nvs_flash.h"

#include "freertos/FreeRTOS.h"
#include "freertos/task.h"

#include "user_config.h"

#include "driver/uart.h"
#include "driver/gpio.h"
#include "driver/hw_timer.h"

#define NOTE_C6  1047
#define NOTE_CS6 1109
#define NOTE_D6  1175
#define NOTE_DS6 1245
#define NOTE_E6  1319
#define NOTE_F6  1397
#define NOTE_FS6 1480
#define NOTE_G6  1568
#define NOTE_GS6 1661
#define NOTE_A6  1760
#define NOTE_AS6 1865
#define NOTE_B6  1976
#define NOTE_C7  2093
#define NOTE_CS7 2217
#define NOTE_D7  2349
#define NOTE_DS7 2489
#define NOTE_E7  2637
#define NOTE_F7  2794
#define NOTE_FS7 2960
#define NOTE_G7  3136
#define NOTE_GS7 3322
#define NOTE_A7  3520
#define NOTE_AS7 3729
#define NOTE_B7  3951

#define QUARTER 4.0
#define THIRD 3.0

#define SPEAKER_PIN 13

//Mario main theme melody
int marioMelody[] = {
  NOTE_E7, NOTE_E7, 0, NOTE_E7,
  0, NOTE_C7, NOTE_E7, 0,
  NOTE_G7, 0, 0, 0,
  NOTE_G6, 0, 0, 0,

  NOTE_C7, 0, 0, NOTE_G6,
  0, 0, NOTE_E6, 0,
  0, NOTE_A6, 0, NOTE_B6,
  0, NOTE_AS6, NOTE_A6, 0,

  NOTE_G6, NOTE_E7, NOTE_G7,
  NOTE_A7, 0, NOTE_F7, NOTE_G7,
  0, NOTE_E7, 0, NOTE_C7,
  NOTE_D7, NOTE_B6, 0, 0,

  NOTE_C7, 0, 0, NOTE_G6,
  0, 0, NOTE_E6, 0,
  0, NOTE_A6, 0, NOTE_B6,
  0, NOTE_AS6, NOTE_A6, 0,

  NOTE_G6, NOTE_E7, NOTE_G7,
  NOTE_A7, 0, NOTE_F7, NOTE_G7,
  0, NOTE_E7, 0, NOTE_C7,
  NOTE_D7, NOTE_B6, 0, 0
};

//Mario main them tempo
int marioNoteDurations[] = {
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  THIRD, THIRD, THIRD,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,

  THIRD, THIRD, THIRD,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
  QUARTER, QUARTER, QUARTER, QUARTER,
};

void gpio_config(GPIO_ConfigTypeDef* pGPIOConfig);

static xTaskHandle tune_task_handle;

static bool state = false;

IRAM_ATTR void toneISR(void) {
  state = !state;
  GPIO_OUTPUT_SET(SPEAKER_PIN, state);
}

void playTune(const int noteMs, const int size, const int melody[], const int noteDurations[]) {

  hw_timer_init();
  hw_timer_set_func(toneISR);

  for (int thisNote = 0; thisNote < size; thisNote++) {

    int noteDurationMs = (int)(noteMs / noteDurations[thisNote]);
    if (melody[thisNote] != 0) {
      hw_timer_arm(((1000 * 1000) / melody[thisNote])/2, true);
    }

    vTaskDelay( noteDurationMs / portTICK_PERIOD_MS );
    hw_timer_disarm();
    GPIO_OUTPUT_SET(SPEAKER_PIN, false);

    int pauseBetweenNotesMs = noteDurationMs * 0.30;
    vTaskDelay( pauseBetweenNotesMs / portTICK_PERIOD_MS );
  }
}

static void tune_task_thread(void* pvParameters) {

    GPIO_ConfigTypeDef io_out_conf;

    io_out_conf.GPIO_IntrType = GPIO_PIN_INTR_DISABLE;
    io_out_conf.GPIO_Mode = GPIO_Mode_Output;
    io_out_conf.GPIO_Pin = BIT(SPEAKER_PIN);
    io_out_conf.GPIO_Pullup = GPIO_PullUp_DIS;
    gpio_config(&io_out_conf);

    GPIO_OUTPUT_SET(SPEAKER_PIN, false);

    playTune(600, sizeof(marioMelody) / sizeof(int), marioMelody, marioNoteDurations);

    vTaskDelete(NULL);
    return;
}

static esp_err_t event_handler(void *ctx, system_event_t *event) {
    switch(event->event_id) {
        case SYSTEM_EVENT_STA_START:
            esp_wifi_connect();
            break;
        case SYSTEM_EVENT_STA_GOT_IP:
            printf("sta got ip ,create task and free heap size is %d\n", esp_get_free_heap_size());
            break;
        case SYSTEM_EVENT_STA_DISCONNECTED:
            /* This is a workaround as ESP32 WiFi libs don't currently
            auto-reassociate. */
            esp_wifi_connect();
            break;
        default:
            break;
    }
    return ESP_OK;
}

static void initialise_wifi(void) {
    tcpip_adapter_init();
    ESP_ERROR_CHECK( esp_event_loop_init(event_handler, NULL) );
    wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
    ESP_ERROR_CHECK( esp_wifi_init(&cfg) );
    ESP_ERROR_CHECK( esp_wifi_set_storage(WIFI_STORAGE_RAM) );
    wifi_config_t wifi_config = {
        .sta = {
            .ssid = SSID,
            .password = PASSWORD,
        },
    };
    ESP_ERROR_CHECK( esp_wifi_set_mode(WIFI_MODE_STA) );
    ESP_ERROR_CHECK( esp_wifi_set_config(ESP_IF_WIFI_STA, &wifi_config) );
    ESP_ERROR_CHECK( esp_wifi_start() );
}

void app_main() {

    UART_SetBaudrate(UART0, BIT_RATE_74880);

    ESP_ERROR_CHECK( nvs_flash_init() );
    initialise_wifi();    
    
	printf("SDK version:%s\n", esp_get_idf_version());

    xTaskCreate(tune_task_thread, "tune_task_thread", 2048, NULL, 7, &tune_task_handle);
}

ghost · 2018-07-12T20:23:48Z

And since the new version of the SDK no longer crashes if I don't initialize WiFi, I could now also test with disabling WiFi (just comment out 'initialise_wifi();').
When I do that the 2ms interruptions disappear. So it seems related to WiFi functioning.

ghost · 2018-07-12T20:37:47Z

Just for comparison, esp8266 Arduino based SDK (using tone/noTone and delay, where tone is written also using hw timer, and delay allows system/wifi operation during a tone) there are no interruptions, even when WiFi is started/starting.

filzek · 2018-07-20T03:30:51Z

I think your problem is related to the WiFi re-connecting issue, not to the interrupt. As you meant before that disabling the WiFi didnt produce 2ms delay anymore it is a WiFi issue per si. Can you try to enable WiFi in AP strict mode without APSTA?

ghost · 2018-08-13T14:29:32Z

Well, since hw_timer_ headers/functions seem to be disappeared, it's hard to test this now :)
Is hw timer functionality available in another header now?

All I want to do is make simple gpio tones, even with wifi functionality running.
This should be possible, ESP8266 Arduino SDK can do this :)
Any suggestions?

ghost · 2018-08-13T17:39:06Z

I tried to use the pwm methods as an alternative (pwm_init etc.), even though the pwm API is not very friendly for tones (one period for all pwm channels/pins).

But it seems when pwm is enabled, vTaskDelay stops working correctly (wrong delay time)..
That might be something for a new issue.. :)

xiongyumail · 2018-10-18T03:26:15Z

hw_timer uses frc1 timer, and in RTOS, it can only be set as a shield interruption source. So when using WiFi, it is easy to be interrupted.

ghost · 2018-10-21T10:20:54Z

So, what would you recommend on RTOS esp8266 as something that would provide a stable enough 'pwm' like signal, to play tones? (while still being able to do wifi) :) Or is it impossible to do that in RTOS?

I'm curious what a 'shield' interruption source is, I don't recognize the term :)

DKrepsky · 2018-11-19T13:22:03Z

This also affects the GPIO ISR. I'm trying to receive an RF signal at base band and the GPIO interrupt works well until this 2ms gap happens. So I'm pretty sure this is an interrupt holding the CPU and blocking all other interrupts.

Is there a way to mask this interrupt other than turning wifi off? Or can this 2ms go down to a few micro seconds?

ghost changed the title ~~HW timer stops 2m every 100ms~~ HW timer stops 2ms every 100ms Jul 5, 2018

27-301 assigned koobest, FayeY and xiongyumail and unassigned koobest Jul 5, 2018

FayeY changed the title ~~HW timer stops 2ms every 100ms~~ [TW#24153] HW timer stops 2ms every 100ms Jul 11, 2018

FayeY removed their assignment Jul 11, 2018

FayeY assigned donghengqaz Oct 22, 2018

DKrepsky mentioned this issue Jun 12, 2019

any timing is lost due interrupt disabling by wifi driver. Please, keep interrupt enabled (GIT8266O-186) #626

Open

dsptech mentioned this issue Sep 17, 2020

os_timer_arm_us alternative (GIT8266O-548) #971

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[TW#24153] HW timer stops 2ms every 100ms #240

[TW#24153] HW timer stops 2ms every 100ms #240

ghost commented Jun 25, 2018 •

edited by ghost

Loading

ghost commented Jul 4, 2018

dudanov commented Jul 5, 2018 •

edited

Loading

ghost commented Jul 5, 2018

ghost commented Jul 12, 2018 •

edited by ghost

Loading

ghost commented Jul 12, 2018

ghost commented Jul 12, 2018

filzek commented Jul 20, 2018

ghost commented Aug 13, 2018

ghost commented Aug 13, 2018

xiongyumail commented Oct 18, 2018

ghost commented Oct 21, 2018 •

edited by ghost

Loading

DKrepsky commented Nov 19, 2018

[TW#24153] HW timer stops 2ms every 100ms #240

[TW#24153] HW timer stops 2ms every 100ms #240

Comments

ghost commented Jun 25, 2018 • edited by ghost Loading

Environment

Problem Description

Expected Behavior

Actual Behavior

Steps to repropduce

Code to reproduce this issue

Debug Logs

Other items if possible

ghost commented Jul 4, 2018

dudanov commented Jul 5, 2018 • edited Loading

ghost commented Jul 5, 2018

ghost commented Jul 12, 2018 • edited by ghost Loading

ghost commented Jul 12, 2018

ghost commented Jul 12, 2018

filzek commented Jul 20, 2018

ghost commented Aug 13, 2018

ghost commented Aug 13, 2018

xiongyumail commented Oct 18, 2018

ghost commented Oct 21, 2018 • edited by ghost Loading

DKrepsky commented Nov 19, 2018

ghost commented Jun 25, 2018 •

edited by ghost

Loading

dudanov commented Jul 5, 2018 •

edited

Loading

ghost commented Jul 12, 2018 •

edited by ghost

Loading

ghost commented Oct 21, 2018 •

edited by ghost

Loading