Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Make time critical sections (microsecond accurate) possible with WiFi on (GIT8266O-244) #680

Open
cranphin opened this issue Aug 13, 2019 · 12 comments

Comments

@cranphin
Copy link

@cranphin cranphin commented Aug 13, 2019

Problem Description

I'm trying to do 1-wire bit banging, where timing should be near microsecond accurate for gpio write and read.
Since the protocol is robust, accuracy is only needed while writing or reading a bit (15-60 us long critical sections).
But I can't get this to work reliably when WiFi is sending, even when doing all of:

  • Changing task priority to 15 (highest)
  • Disabling -all- interrupts using XTOS_DISABLE_ALL_INTERRUPTS
  • Adding IRAM_ATTR

With all of this, sometimes I still get a 10us extra delay in my timing/critical code.
Is there anything else I can disable/change? Any idea what might still be interrupting my code? :)

Note that WiFi is still stable like this, and my critical sections are very short, so I hope it should be possible :)

See also: https://bbs.espressif.com/viewtopic.php?f=7&t=9553

Code to reproduce this issue

Task which runs the code:

	const BaseType_t ret = xTaskCreate(ds_task,
					"ds_task",
					2048,
					NULL,
					// See https://docs.espressif.com/projects/esp8266-rtos-sdk/en/latest/api-guides/system-tasks.html for prio's
					15, // Can't go higher, who cares about stable WiFi.
					&ds_task_handle);

Includes/defines

#include <xtensa/xtruntime.h>
#include "esp8266/gpio_struct.h"
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"

// At microsecond speeds, the functions from gpio.h are too heavy
#define GPIO_FAST_SET_1(gpio_num) GPIO.out_w1ts |= (0x1 << gpio_num)
#define GPIO_FAST_SET_0(gpio_num) GPIO.out_w1tc |= (0x1 << gpio_num)
#define GPIO_FAST_OUTPUT_ENABLE(gpio_num) GPIO.enable_w1ts |= (0x1 << gpio_num)
#define GPIO_FAST_OUTPUT_DISABLE(gpio_num) GPIO.enable_w1tc |= (0x1 << gpio_num)
#define GPIO_FAST_GET_LEVEL(gpio_num) ((GPIO.in >> gpio_num) & 0x1)

The method with the critical section

uint32_t IRAM_ATTR onewire_read_bit(void) {
	uint32_t r;

	uint32_t savedLevel = XTOS_DISABLE_ALL_INTERRUPTS;

	GPIO_FAST_OUTPUT_ENABLE(ONEWIRE_PIN);
	GPIO_FAST_SET_0(ONEWIRE_PIN);

	ets_delay_us(3);

	GPIO_FAST_OUTPUT_DISABLE(ONEWIRE_PIN);

	ets_delay_us(10); // Somewhere near here, sometimes we still get 10us extra delay

	r = GPIO_FAST_GET_LEVEL(ONEWIRE_PIN);

	XTOS_RESTORE_INTLEVEL(savedLevel);

	usleep(53);

	return r;
}
@github-actions github-actions bot changed the title Make time critical sections (microsecond accurate) possible with WiFi on Make time critical sections (microsecond accurate) possible with WiFi on (GIT8266O-244) Aug 13, 2019
@dsptech

This comment has been minimized.

Copy link

@dsptech dsptech commented Aug 17, 2019

Hi,
I never seen a such case, but if you get an extra latency inside the "critical section" (interrupts totally disabled, even NMI), I suppose that ets_delay_us() perform other jobs than delays.
I think that you could try to write your own micro_us delay function by using the soc_get_ccount() macro.
The macro return the current cpu clock tick number.
Regards.

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 17, 2019

I've always assumed ets_delay_us was not much more than a loop.
My assembler is a bit rusty, but someone has got the code for ets_delay_us :)
https://github.com/trebisky/esp8266/blob/a886c2ff582d9c368f5d9d669f31cc66105a44ad/reverse/bootrom/boot_OLD.txt#L5510
https://github.com/trebisky/esp8266/blob/a886c2ff582d9c368f5d9d669f31cc66105a44ad/reverse/bootrom/boot.txt#L6117
At a glance I don't see anything special going on

Maybe I didn't actually turn of all the interrupts somehow, or I'm missing something else. I'll try to make a smaller sample focused on just this :) I'm using a logic analyzer to get the timings, so I'm pretty certain about the delay, things are as expected for many bits sent, and then there's a sudden delay. Small, but enough to miss the pulse I need to check :)

Note to self: look at this too https://sub.nanona.fi/esp8266/timing-and-ticks.html

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 17, 2019

I've copied pasted the ets_delay_us assmbly and comments from the links from my previous comment:

ets_delay_us:
40002ecc:   12c1f0      addi    a1, a1, -16           ; stack
40002ecf:   d26102      s32i    a13, a1, 8            ; save a13
40002ed2:   c911        s32i.n  a12, a1, 4            ; save a12
40002ed4:   0901        s32i.n  a0, a1, 0             ; save return

40002ed6:   cd02        mov.n   a12, a2
40002ed8:   c5e50a      call0   xthal_get_ccount      ; 0x4000dd38
                      
40002edb:   01fbff      l32r    a0, [0x3fffc704]      ; 0x40002ec8
40002ede:   0800        l32i.n  a0, a0, 0             ; reads 80 if 80 Mhz
40002ee0:   dd02        mov.n   a13, a2
40002ee2:   c0c082      mull    a12, a0, a12
40002ee5:   05e50a      call0   xthal_get_ccount      ; 0x4000dd38
40002ee8:   d032c0      sub a3, a2, a13
40002eeb:   c7b308      bgeu    a3, a12, 0x40002ef7

; polling loop does delay
40002eee:   85e40a      call0   xthal_get_ccount      ; 0x4000dd38
40002ef1:   d042c0      sub a4, a2, a13
40002ef4:   c734f6      bltu    a4, a12, 0x40002eee
40002ef7:   c811        l32i.n  a12, a1, 4            ; restore a12
40002ef9:   d821        l32i.n  a13, a1, 8            ; restore a13
40002efb:   0801        l32i.n  a0, a1, 0             ; return
40002efd:   12c110      addi    a1, a1, 16            ; stack
40002f00:   0df0        ret.n

40002f02:   0000
@dsptech

This comment has been minimized.

Copy link

@dsptech dsptech commented Aug 17, 2019

Hi,
the assembler is rusty also to me, but I agree: this code is a simple delay loop.
Regarding interrupts disabling, I think that there is no other ways.

Sorry, I have no other realistic ideas. I think that the question need a reply by espressif staff.
Regards.

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 18, 2019

Created a fairly minimal sample to display the issue:
https://github.com/cranphin/TimingTest/tree/6701850173ccb78df91525c44b5091bea9eae0b1

It does some delay + gpio, and measures the timing using ccount.
Most of the time, the measurement shows 14us (1170 cpu cycles at 80mhz).
But with WiFi sending, now and then there's a longer delay, which it logs.
Example run (the last value is delay in usec, which should be 14, but it's more):
I (4895) main: 7:2304(28)
I (7472) main: 35:2221(27)
I (12418) main: 1:1651(20)
I (12935) main: 24:2111(26)
I (14379) main: 26:1408(17)
I (14382) main: 36:1935(24)
I (19431) main: 5:2264(28)
I (26954) main: 27:1759(21)
I (30973) main: 8:2679(33)
I (36125) main: 2:2262(28)
I (40660) main: 39:2165(27)
I (40765) main: 46:2037(25)
I (42414) main: 9:2154(26)
I (44888) main: 29:1548(19)
I (48392) main: 14:1999(24)
I (50660) main: 39:1488(18)
I (52413) main: 34:1598(19)

I really want to know what causes the delay in this sample, and how to turn it off :)

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 18, 2019

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 18, 2019

And semi-interestingly, even removing MQTT I still see some delays, but less often. But I guess WiFi still does things, even without TCP traffic :)

@donghengqaz

This comment has been minimized.

Copy link
Collaborator

@donghengqaz donghengqaz commented Aug 20, 2019

To realize the real time controlling, you should do following:

  1. close all hardware exception by API
    vPortETSIntrLock(exit one is vPortETSIntrUnlock)
  2. the API ets_delay_us may not cause the real time delaying. because the previous coding boy had not considered the time cost of the API it self, so you may reduce some the inputting time count value by testing

I hope the upper advices can help you.

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 20, 2019

I hope the upper advices can help you.

First test shows vPortETSIntrLock() and vPortETSIntrUnlock (with #include "rom/ets_sys.h") improving timing stability a lot! :)
I still get a spurious 2us delay (179 ticks), but that's small enough to not care about :)
And have to investigate more still! :)

It looks like these mystical lines are the special sauce (on top of disabling interrupts):
Open

            do {
                REG_WRITE(INT_ENA_WDEV, WDEV_TSF0_REACH_INT);
            } while(REG_READ(INT_ENA_WDEV) != WDEV_TSF0_REACH_INT);

Close

            extern uint32_t WDEV_INTEREST_EVENT;
            REG_WRITE(INT_ENA_WDEV, WDEV_INTEREST_EVENT);

void IRAM_ATTR vPortETSIntrLock(void)

Seems wdev is WiFi related, and not well documented or understood, but I'm happy as long as this works ^_^

@dsptech

This comment has been minimized.

Copy link

@dsptech dsptech commented Aug 20, 2019

Very precious information here !
Thank you @donghengqaz

@cranphin

This comment has been minimized.

Copy link
Author

@cranphin cranphin commented Aug 20, 2019

And another bit, the occasional 2us delay I still saw disappeared by setting my task priority to 15.
So maybe some task switching was still happening :)

So with that, here's an updated sample which has very predictable timing.
Only the first fake 'read' in my loop still has varied timing, but I think it's just how the compiler/cpu deals with things, caching and such, not being interrupted. And the change is small, with this it should be easy to make a reliable 1-wire bus :)
https://github.com/cranphin/TimingTest/tree/58f0e33fc50a7613fd2872162ba5409580d86e97

@AntoinedeChassey

This comment has been minimized.

Copy link

@AntoinedeChassey AntoinedeChassey commented Nov 26, 2019

Thanks for sharing @cranphin, I found your issue while having some random errors of DS18B20 temperature sensor readings.
Sometimes, I randomly get bad measurements, probably because of this us delay from the WiFi stack (and because my sensor reading task priority was set to 0).
I will try with setting it to 15 and see how it behaves!
This could also (probably) help before reading / sending bits to the sensor: freertos.org/taskENTER_CRITICAL_taskEXIT_CRITICAL.html
Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
4 participants
You can’t perform that action at this time.