strange timing with setTimeout

Posted on
  • During testing a rotary phone, I ran into problems recognizing pulses.

    After some testing brought it down to following samples.
    Duration is always much more than expected (by me).

    Interesting is last example where only first timeout is wrong.

    Testing is done with WebIde. First examples use terminal window for input.
    Last testing is uploaded from editor window and called from terminal.
    Board is MDBT42Q with 2v06, downloaded from binary

    for(var i = 0; i < 10; i++) {var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},1000);}
    =undefined
    2159.7900390625
    2161.0107421875
    2162.90283203125
    2164.21508789062
    2165.67993164062
    .....
    
    var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    958.46557617187
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    1476.01318359375
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    1280.94482421875
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},1000);
    =1
    1865.69213867187
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},1000);
    =1
    2315.673828125
    
    function tst(duration){
      var pnt = 0;
      function tstTimeout(){
        var dt = new Date();
        setTimeout(function(){ 
          console.log(new Date() - dt);
          if(pnt++ < 4) tstTimeout();
        },duration);
      }
      clearTimeout();
      tstTimeout();
    }
    tst(1000);
    =undefined
    1828.857421875
    1001.43432617187
    1001.46484375
    1001.43432617187
    1001.46484375
    
  • Is it possible you have some other interval or setWatch running in the background that could be keeping it really busy? Maybe try a reset(1) to be sure?

    From a board I just tried:

    >for(var i = 0; i < 10; i++) {var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},1000);}
    =undefined
    992.88940429687
    994.90356445312
    996.18530273437
    997.86376953125
    999.1455078125
    1000.42724609375
    1002.01416015625
    1003.44848632812
    1004.73022460937
    1010.58959960937
    
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    101.13525390625
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    101.25732421875
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    101.13525390625
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    101.13525390625
    >var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    =1
    101.13525390625
    
    
    >function tst(duration){
    :  var pnt = 0;
    :  function tstTimeout(){
    :    var dt = new Date();
    :    setTimeout(function(){
    :      console.log(new Date() - dt);
    :      if(pnt++ < 4) tstTimeout();
    :    },duration);
    :  }
    :  clearTimeout();
    :  tstTimeout();
    :}
    =function (duration) { ... }
    >tst(1000);
    =undefined
    1001.55639648437
    1001.67846679687
    1001.52587890625
    1001.52587890625
    1001.46484375
    

    So all that looks pretty good. You'd expect the ~1ms delay because of the time taken to parse and execute setTimeout after the initial Date variable is created.

  • Sorry, you're right. Just tried with version 2v06 and something isn't right.

    Please could you try a cutting edge build? That's what I tried before and it worked fine.

  • Hmm,
    tested with 2V06,78 from http://www.espruino.com/binaries/travis/­master/
    Still same problem.
    Latest entry is from 2020-07-30
    Looks like there is no update since end of July

  • Tested with Android and nrf
    Got same problem, so its not a windows problem.
    With Android its even worth, first time it takes >30 secs

  • Just seen new version(V2.06.81) in binaries.
    I did some extended testing with other boards

    board V2.04 V2.06
    ========= ===== =====
    Espruino ok ok
    ESP32 ok ok
    MDBT42Q ok bad
    Puck ok bad

    Based on that, my first guess would be somewhere around implementation of UART for BLE

  • Thanks - so it'll be related to the nRF52 I guess.

    I think it's less likely to be a BLE issue, because the entire line is executed only when you hit enter - so in your example - especially var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100); - the UART shouldn't be doing anything while code is running.

    I guess it could be related to the 'Utility Timer' somehow - that is platform-specific and may have some issues

  • Hmm, some more (may be helpful) info
    One more problem I have around is disconnecting of UART on MDBT42Q.
    Did not encounter this with Puck (yet?)
    From time to time it happens, that connection is kind of frozen. There is no echo in terminal window anymore. This happens at crlf or in the middle of a command.
    Or, another problem, sending even some lines of code, less than 3kb, from source window to Espruino stops somewhere in the middle.
    And one more, sometimes after reset, startinfo comes in very slow only, char by char.

  • That's a strange one. Does Ctrl-C sort it out? Or does the Web IDE console show a flow control message?

  • Ok, I'm pretty sure I've figured this out now. It's definitely a firmware issue that's been around for a while I think.

    In fact if you:

    • Paste in var dt = new Date();setTimeout(function(){console.log­(new Date() - dt);},100);
    • Wait X seconds then press Enter
    • Timeout happens X seconds after this

    It's to do with the device sleeping - you probably don't notice it in STM32 boards because they don't sleep when you're connected via USB

  • Ok, just fixed! If you try a cutting edge build now it should be sorted.

    It seems this got introduced about 2 months ago and got into 2v06. Just a really minor change that had a big effect!

    I doubt this will affect your connection issues - but the only times I've had issues with that is when there's extremely poor signal strength.

  • Its fixed and works fine. Well done ;-)
    Connection issue did happen one time only today.
    Usual problem, if you want to show strange behaviour, it never happens :-(
    Poor signal should not be the problem, distance between board and laptop is less than 20cm

  • Post a reply
    • Bold
    • Italics
    • Link
    • Image
    • List
    • Quote
    • code
    • Preview
About

strange timing with setTimeout

Posted by Avatar for JumJum @JumJum

Actions