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

Implement Espruino setWatch on ESP8266 #643

Closed
samehhady opened this issue Oct 10, 2015 · 32 comments
Closed

Implement Espruino setWatch on ESP8266 #643

samehhady opened this issue Oct 10, 2015 · 32 comments
Assignees
Labels
bug ESP8266 This is only a problem on ESP8266 devices implemented

Comments

@samehhady
Copy link

I've been trying the IRReceiver module on ESP8266 and found that it is using setWatch
Currently this functionality is not implemented yet on ESP.

Talking to @nkolban he mentioned that at a minimum, it looks like ESP8266 has to implement jshPinWatch and jshCanWatch which are stubbed to be "NONE" and "false" right now.

@nkolban nkolban added bug ESP8266 This is only a problem on ESP8266 devices labels Oct 10, 2015
@nkolban
Copy link
Contributor

nkolban commented Oct 10, 2015

Today, jshCanWatch for ESP8266 returns false for every pin indicating that none of the pins are able to support interrupt driven change detection. Further, jshPinWatch is stubbed to do nothing.

@soswow
Copy link

soswow commented Oct 11, 2015

Oh, finally I found this issue after an hour debugging and understanding why library http://www.espruino.com/DHT22 doesn't work =) (it was using setWatch)

@gfwilliams
Copy link
Member

Yes, I think people are going to end up a bit disappointed when they try the really realtime stuff lime WS2811 and DHT11/IR/radio/etc

I'm tempted to put a bit of a note after the Espruino banner that mentions it's not 100%? it would suck if people got the wrong impression about Espruino itself because of the ESP8266 port

@soswow
Copy link

soswow commented Oct 11, 2015

@gfwilliams I was aware it's a Beta, and I know it was brought in very lately from separate repo, so I am not surprised or disappointed much. That's BETA is for. But maybe having it said explicitly is good enough.

@nkolban
Copy link
Contributor

nkolban commented Oct 11, 2015

But the GREAT news is that ESP8266 does indeed has interrupt handling for GPIOs ... it simply hasn't been implemented in the ESP8266 port yet. Weve been studying the Espressif SDK and it doesn't look like rocket science to add it. As such, that would then tell me that the speed of running Espruino on the ESP8266 should be no worse than other boards that are also capable of running at 160MHz.

@gfwilliams
Copy link
Member

Yes, really good news about the IRQs. And @tve implemented the utility timer - does that run off a proper IRQ as well?

the speed of running Espruino on the ESP8266 should be no worse than other boards that are also capable of running at 160MHz.

Unfortunately that's probably not entirely right - the ESP8266 is having to load a lot of program code out of SPI flash in order to run it (as far as I'm aware?) so I think realistically it's going to end up slower than even the 72Mhz parts that can execute out of on-chip flash... Not that it actually matters much though.

@nkolban nkolban self-assigned this Oct 11, 2015
@nkolban
Copy link
Contributor

nkolban commented Oct 11, 2015

Now it is time to write a use case that should work ... and then we can test against it.

The primary docs for this area can be found here:

http://www.espruino.com/Reference#l__global_setWatch

The sample test that we are working with just now looks like:

print("Starting watch set test\n");
var testPin = new Pin(12);
var watchId = setWatch(function() {
  print("The callback function was called for a pin I/O change\n");
}, testPin);
print("A new watch was set up with id=" + watchId + "\n");

The principle behind this is that it will start watching GPIO12 for a signal change and, should it happen, cause the callback to be invoked.

In the ESP8266 SDK, we have the following functions that come into play when working with interrupts:

  • gpio_init - Initialize the ESP8266 GPIO subsystem - called in jshInit.
  • gpio_intr_handler_register - Register a callback that is invoked when a GPIO changes state - called in jshInit..
  • gpio_pin_intr_state_set - Set whether a specific pin will cause the interrupt handler to be invoked - called in jshPinWatch.
  • gpio_intr_ack - Flags an interrupt as having been handled - called in intrHandlerCB.

With these parts wired in, we are detecting that the interrupt handler is indeed seeing a pin state change ... but only once. When the pin state changes from high to low or low to high, we see the interrupt handler invoked ... but only the first time. If the pin state changes again, we don't see any further interrupt invocation. This is the area that is currently being investigated.

... much later ...
Finally got a working permutation ... in my interrupt handler I have to:

gpio_intr_ack(interruptMask);
...
gpio_pin_intr_state_set(GPIO_ID_PIN(pin), GPIO_PIN_INTR_ANYEDGE);

And now it works flawlessly. Do I proclaim to 100% understand this? No. I have some guesses ... but nothing for certain.

Now that I can mechanically detect interrupt changes, the next step will be linking these into the Espruino event processing logic. .... To Be Continued ...

@gfwilliams
Copy link
Member

the next step will be linking these into the Espruino event processing logic. ....

Just call jshPushIOWatchEvent(EV_EXTI0); - as ESP8266 doesn't have many pins, I think EXTI0..15 could probably be the pin number? In STM32 there are only 16 edge-detectors for interrupts, so you can only have 16 interrupts at once

@soswow
Copy link

soswow commented Oct 12, 2015

@nkolban maybe better write new messages? =) I was monitoring email for updates, because I am very interested and just found out you've been updating same comment ) Maybe @gfwilliams haven't noticed your progress for the same reason? =)

@nkolban
Copy link
Contributor

nkolban commented Oct 12, 2015

@soswow There is a balance at work here .... the way I like to work is to make sure that I keep a trail of the learnings so that when I come back to an issue a few days later, I remember where I was. In addition, I am always looking for help and collaborators so keeping the story straight is super useful. I am also of an opinion that down the line, someone else may want to modify code that was previously written and the comments here might be useful for someone else.

However, I don't want to flood everyones email in boxes with comment after comment. So the choices appear to be to:

  1. Not make comments until the end
  2. Make comments in a file and then paste the file as a comment at the end
  3. Update last comment as I go along (what I am doing now)

@gfwilliams
Copy link
Member

I'm happy with the last comment changes - I saw them before I wrote up...

My e-mail box is usually pretty full with GitHub comments from @nkolban as it is ;)

@soswow
Copy link

soswow commented Oct 12, 2015

@nkolban do as you like and feel right, of cause! And I am 100% for detailed trail of thought kinda comments with all those benefits you described above. As for flooding peoples inboxes - I was thinking if someone not interested in updates on an issue he can just unwatch it.
Thank you for your work! =)

@nkolban
Copy link
Contributor

nkolban commented Oct 13, 2015

Following on from @gfwilliams comments yesterday, now starting on the invocation of the event push to Espruino when an interrupt occurs.

... later ...

I implemented a call to jshPushIOWatchEvent(EV_EXTI0 + pin) when the GPIO pin interrupt occurred. I see that then makes a callback to jshGetWatchedPinState() which retrieves the state of the pin that was interrupted .... however ... what I am not yet seeing is a callback to my registered callback function that was defined at the JS level. So things aren't quite right yet.

On a fresh boot I run trace() and see the following for the array called watches:

#9[r1,l2] Name String [2 blocks] "watches"        #11[r2,l1] Array(0) [ ]

after running my script which creates one watch, I see:

#9[r1,l2] Name String [2 blocks] "watches"        #11[r2,l1] Array(2) [
          #79[r1,l2] Name Integer 1            #74[r1,l1] Object {
              #76[r1,l2] Name String [1 blocks] "pin"                #75[r1,l1] Pin 5
              #77[r1,l2] Name String [2 blocks] "callback"                #54[r1,l1] Function {
                  #73[r1,l2] Name String [1 blocks] "ÿcod"                    #53[r1,l1] String [10 blocks] "{\n  print(\"The callback function was called for a pin I/O change\\n\");\n}"
                }
            }
        ]

I'm still trying to understand these trace decodes. The thing that has drawn my attention is the apparent size of the watches array. I would have expected it to be 1 and not the apparent 2. It would be 1 because I have added 1 watch and in fact the data seems to show just 1 ... but if we look carefully, we seem to see the size of the array as 2 (Array(2)).

... later ...

It appears to me that the algorithm at play is becoming clearer. When a GPIO interrupt occurs we add an event into the IOEvent list which gets processed in jshIdle. In there, we then ask what kind of event it is ... and if it is a GPIO interrupt ... then we handle it as such.

... later ...

Finally nailed down the last issue (at this time). There is one more hardware (ESP8266) specific function that had not been implemented and that was jshIsEventForPin which had been not fully implemented. Once done, everything has now fallen into place and interrupt handling appears to be working.

@nkolban
Copy link
Contributor

nkolban commented Oct 13, 2015

Pull request issued for inclusion of the interrupt handler logic. Waiting on @samehhady to perform tests before closing the work item.

@soswow
Copy link

soswow commented Oct 13, 2015

@nkolban is there binary I can use to test DHT22 library? I have hardware set up

@nkolban
Copy link
Contributor

nkolban commented Oct 13, 2015

A binary of the firmware that includes the setWatch logic can be found here.

@soswow
Copy link

soswow commented Oct 13, 2015

Thanks. I tried it out. My DHT22 doesn't work. It doesn't complain about setWatch being set on something that's already watched (As before) but it returns -1 -1 as data. Maybe I hooked up DHT22 component incorrectly. I'll try with arduino later.
For now - I see this output
Pin error: pin 16 is >= 16 ... and port = 83
when I deploy simplest scenario (with Espruino Web IDE):

setWatch(function(){
  console.log('changed');
}, D2, {repeat: true});

It still shows "changed" every time I change second pin from 0 to 3.3V thought
screenshot 2015-10-13 19 06 30

@nkolban
Copy link
Contributor

nkolban commented Oct 13, 2015

The Pin error message will be removed in the next binary build. It was added for debugging purposes but foolishly left in. It has been removed from the master Espruino source tree and will be gone in next binary. That message that you are seeing just now can be ignored though as it will always show up.

Your example setWatch seems to be working correctly. Is that your opinion as well? If I read that statement correctly it is saying that when the signal level on pin D2 changes, log a console message ... which I think is what you are saying.

Unfortunately I am on the road this week and away from electronics ... so I don't have a DHT22 available to me where I am to attempt a device test. The soonest I could look at an actual DHT22 recreate will be Saturday.

gfwilliams added a commit that referenced this issue Oct 13, 2015
@gfwilliams
Copy link
Member

Maybe try it out with a signal source from somewhere else (a normal Espruino board?) and dump the time:

setWatch(function(e){
  console.log(e.time - e.lastTime);
}, D2, {repeat: true, edge:"both"});

IIRC the DHT22 actually sends signals pretty quickly, so it could be watches are working, but:

  • The timing isn't accurate enough - if it were from an RTC it might only be accurate to 32kHz
  • The IRQ just can't be serviced quickly enough
  • The messages from the IRQ can't be handled fast enough and drop off the bottom of the queue

Maybe also check E.getErrorFlags() to see if there were any overflows

@soswow
Copy link

soswow commented Oct 13, 2015

yes, with this example it works for me. I don't have logic analyser to see what my device (DHT22) spitting out to understand if setWatch doesn't work correctly or my devices doesn't spit what it should.
https://github.com/espruino/EspruinoDocs/blob/master/devices/DHT22.js - this is a lib.

Interesting ... I modified this code a bit and added console.log(JSON.stringify(t)); as the first line of DHT22.prototype.onwatch function. And this is what I see:

{"time":137.796043,"pin":D2,"state":true}
{"time":138.178922,"pin":D2,"state":true}
{"time":138.562814,"pin":D2,"state":true}
Temp is -1 and RH is -1

Is it normal, is switches only from true to true? Shouldn't it trigger onwatch function when goes down?

...
E.getErrorFlags() is empty for me
....
And where is lastTime in my example ...
...
I see library is actually heavily depends on timing. Maybe @gfwilliams right and esp8266 just not fast enough?

@gfwilliams
Copy link
Member

{"time":137.796043,"pin":D2,"state":true}
{"time":138.178922,"pin":D2,"state":true}
{"time":138.562814,"pin":D2,"state":true}

Well, if that really is only triggering once every half second, it's definitely not fast enough!

The repeated state:true happens when the pin changes state so quickly it goes to 0 and then back to 1 before the IRQ happens.

@soswow
Copy link

soswow commented Oct 13, 2015

I have to do other things right now. But when I back I will use another microcontroller (As you suggested @gfwilliams) and will start sending toggling signal into esp8266 with some interval, which I can decrease over time and see when esp8266 will start falling behind

@soswow
Copy link

soswow commented Oct 13, 2015

Ok. I have arduino nano running with this code:

int led = 7;

void setup() {                
  pinMode(led, OUTPUT);     
}

void loop() {
  digitalWrite(led, HIGH);
  delay(1);
  digitalWrite(led, LOW);
  delay(1);
}

And I hooked up pin 7 and ground to esp8266. On esp I am running this:

var lastState = null;
setWatch(function(t) {
  if(lastState !== null){
    if(lastState === t.state){
      console.log("error");
    }
  }else{
    console.log("starting");
  }
  lastState = t.state;
}, D2, {repeat: true, edge: "both"});

I don't get any "error". Which mean there were no two sequential true or false

The only problem I have is that after maybe 10 seconds of this JS code running devices resettes itself with possible error:

ets Jan  8 2013,rst cause:2, boot mode:(3,7)
load 0x40100000, len 29488, room 16
tail 0
chksum 0xfa
load 0x3ffe8000, len 2108, room 8
tail 4
chksum 0x08
load 0x3ffe8840, len 28828, room 4
tail 8
chksum 0x09
csum 0x09
��äÉnâ��åÍõ²Â�ʲ��Ñ�õ²¢ªª�����j¤DëËë��¤×®�$.],H[Y[�²ata
r��Nÿ

before that it was something ending with

�ÛäÉnâ sys=68096 rtc=642893080
don't use rtc mem data
r��Nÿ

@gfwilliams
Copy link
Member

Maybe try a bit slower?

If you print too much stuff, the ESP8266 is going to block and wait for what you printed to be sent out the serial port - if it blocks too long it might reset.

What about:

var c = 0;
setWatch(function() {c++;}, D2, {repeat: true, edge: "both"});
setInterval(function() {
  console.log(c);
  c=0;
}, 1000);

@soswow
Copy link

soswow commented Oct 13, 2015

It wasn't printing anything before. With your code it's 100 almost all the time (every 14th number is 99) and it's not crashing.

@gfwilliams
Copy link
Member

Ok, that's good news (i think)? But you're sending a 500Hz signal so you'd expect 500 (actually 1000 since it's on both edges)?

@soswow
Copy link

soswow commented Oct 13, 2015

yes. With delay(10) it still 100/90 pair. With 15 it's 66, with 20 it's 50. And esp8266 still keep crashing and restarting now with

 ets Jan  8 2013,rst cause:1, boot mode:(3,6)
load 0x40100000, len 29488, room 16
tail 0
chksum 0xfa
load 0x3ffe8000, len 2108, room 8
tail 4
chksum 0x08
load 0x3ffe8840, len 28828, room 4
tail 8
chksum 0x09
csum 0x09
�ÛäÉn���åÍõ²Â�ÊÂ��Ñ�õ���ª¢�Êür���¹lÀÄ��ÿ

Maybe USB provided power is not enough ...

@nkolban
Copy link
Contributor

nkolban commented Oct 13, 2015

Since Espruino is a JavaScript interpreter (as I understand it), that means that the path length to execute a JS statement is much, much longer than C statements performing the equivalent, GPIO bit twiddling will never (opinion) be as fast as native C code. My understanding of how the interrupt handler works is:

(1) An interrupt occurs
(2) The interrupt handler gets control
(3) The interrupt handler asks the PIN for its current signal value
(4) A new I/O record is created and placed on the IO queue
(5) The interrupt handler ends
(6) The next time the JavaScript engine goes idle (not executing other JS instructions) ...
(7) ... it examines the IO queue and processes this queue (and all others)
(8) The IO event is removed from the IO queue and the JS callback is invoked

As we can see, this is very different from an Arduino style app which might:

void loop() {
    if (pinValue(pin) != lastValue) {
       lastValue = pinValue(pin);
       // Handle a pin value change
    }
}

It is likely the performance of the current interrupt handler can be dramatically improved from where it is ... and the reason for this is that there is a metric ton of debugging information being written that gets processed in the idle loop. We will add an issue to disable debug logging for timing tests such as this.

Issue #655 added to allow disabling of debug information for ESP8266.

@gfwilliams
Copy link
Member

there is a metric ton of debugging information being written

That'd do it - if it's outputting down RS232 that'd slow things down no end - however it's kind of odd that it settles down at exactly 100 IRQs per second.

@soswow
Copy link

soswow commented Oct 13, 2015

@gfwilliams the last thing I probably need to do is to eliminate Arduino factor and make sure it actually sends blinking signal with the speed I ask it to do. This was arduino Nano. I will use some other microcontroller and try to reed this signal as well.

@nkolban is it possible my esp8266 is out of ram because each event trigger do some debugging logging or some other type of memory leaking because code still contains debug entries? Is there a way to access memory usage?

@nkolban
Copy link
Contributor

nkolban commented Oct 13, 2015

@soswow Let me invite you to come and drop by on our live Gitter stream found here:

https://gitter.im/espruino/Espruino

This is a great place to ask and answer questions in real time.

@nkolban
Copy link
Contributor

nkolban commented Oct 19, 2015

@samehhady has reported that setWatch is not working. This is not the same as all interrupt abilities are now 100% but as of now, there are no known defects on interrupt handling/setWatch.

@nkolban nkolban closed this as completed Oct 19, 2015
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug ESP8266 This is only a problem on ESP8266 devices implemented
Projects
None yet
Development

No branches or pull requests

4 participants