Add stack trace to code recursively scheduling timers #325

alistairjcbrown · 2020-05-17T10:52:04Z

Purpose (TL;DR) - mandatory

Fix issue #230 by using stack information for jobs and timers to provide more context when an infinite loop error is thrown.

Solution - optional

This solution works by adding a stack property to jobs and tasks. This data can then be used, if an infinite loop is detected, to set the stack of the thrown infiniteLoopError.

Example stack trace from test run

Error: Aborting after running 5 timers, assuming an infinite loop!
Timeout - recursiveCreateTimerTimeout
      at recursiveCreateTimer (test/fake-timers-test.js:4668)
      at recursiveCreateTimerTimeout (test/fake-timers-test.js:4669)
      at callTimer (src/fake-timers-src.js:441)
      at Object.next (src/fake-timers-src.js:1039)
      at src/fake-timers-src.js:1128

codecov · 2020-05-17T10:53:02Z

Codecov Report

Merging #325 into master will increase coverage by 0.39%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master     #325      +/-   ##
==========================================
+ Coverage   93.12%   93.52%   +0.39%     
==========================================
  Files           1        1              
  Lines         553      587      +34     
==========================================
+ Hits          515      549      +34     
  Misses         38       38

Flag	Coverage Δ
#unit	`93.52% <100.00%> (+0.39%)`	⬆️

Impacted Files	Coverage Δ
src/fake-timers-src.js	`93.52% <100.00%> (+0.39%)`	⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update cb4c2f6...d95493e. Read the comment docs.

src/fake-timers-src.js

SimenB · 2020-05-17T11:45:16Z

Could we just keep track of the last scheduled timer instead of all scheduled timers? Not sure how much that matters

SimenB · 2020-05-17T18:36:45Z

Another thought, this is mostly meant to catch timers added while running timers. Could we add some flag internally that's set to true whenever we run timers, and only collect these at that time?

alistairjcbrown · 2020-05-17T21:08:35Z

@SimenB Thanks for the feedback!
I've updated to set an error object on the job instead of getting the error stack. The second commit adds in a isNearInfiniteLimit flag which is used to decide whether to attach an error object to the job. Jobs from the job before we hit the limit will have an error property populated, which is then used if we need to create an InfiniteLoopError. What do you think?

fatso83 · 2020-05-19T19:40:54Z

no time (parental leave) at the moment to look at PRs, sorry.

benjamingr · 2020-05-19T19:58:11Z

src/fake-timers-src.js

+                " timers, assuming an infinite loop!"
+        );
+
+        var sliceSize = job.type ? 4 : 3;


It would be ideal to calculate this by looking for ourselves in the stack trace rather than setting prefixed sizes. This can fail based on adding new jobs.

benjamingr · 2020-05-19T19:58:54Z

src/fake-timers-src.js

+
+        var sliceSize = job.type ? 4 : 3;
+
+        infiniteLoopError.stack =


Some environments don't have a writeable stack property - so it would be better to wrap this in a try/catch and to use defineProperty

In particular we had this issue several times in bluebird which also mutates stacks

benjamingr

Hey, left a few comments.

Code looks good in principle - the things I'd want to see to approve (other collaborators may approve before I'm not blocking):

Tests that check a larger chunk of the stack (so we're sure this doesn't break) .
Dealing with a non-writeable stack property.

I'll approve if those two get addressed even without calculating the slice size automatically.

benjamingr · 2020-05-19T20:05:06Z

Also:

What do you think?

The actual implementation logic lgtm

alistairjcbrown · 2020-05-19T21:52:31Z

@benjamingr Awesome, thanks for the feedback! I'll take a run through it tomorrow night 👍

alistairjcbrown · 2020-05-20T21:36:40Z

@benjamingr

Dealing with a non-writeable stack property

Using defineProperty wrapped in try/catch as suggested - TIL about non-writeable stacks 👍

calculating the slice size automatically

Doing this by running through the stack line by line, checking the line matches at target.X (where X may be (anonymous function) or <computed>) or at Object.Y (where Y is a clock method).

Tests that check a larger chunk of the stack (so we're sure this doesn't break)

Apologies, I wasn't 100% sure on what this was asking, so I've added more tests to cover requestAnimationFrame, setImmediate, setInterval, requestIdleCallback, nextTick.

If this was referring to checking more of the stack trace itself, the tests are checking that we're getting the expected method at the top of the stack - but we can't check the filename as it'll be __puppeteer_evaluation_script__ on headless. Do you want more of the stack trace checked?

benjamingr

Latest version LGTM. Thanks for this - this makes debugging easier :)

Let's give other members a few days to respond before merging.

benjamingr · 2020-06-06T20:20:14Z

Hey, I wanted to merge and it looks like there is a merge conflict - can you please take a look?

Use stack information for jobs and timers to provide more context when an infinite loop error is thrown. Fixes sinonjs#230

Use a flag when approaching infinite loop detection which will enable an error object to be attached to the job, which can then be used for generating the stack output.

- Safely update stack property using `defineProperty`, wrapped in try/catch - Tests for more clock functions to confirm stack trace provided - Stack trace slice automatically calculated based on clock function position

- Use global setInterval and setImmediate to match setTimeout use - Remove unnecessary duration parameter from setImmediate and setImmediate

alistairjcbrown · 2020-06-08T20:25:39Z

@benjamingr Rebased off master and conflict resolved 👍

benjamingr · 2020-06-08T20:32:14Z

Thanks!

fatso83 · 2020-09-14T11:34:24Z

This broke the builds on Safari, IE and Firefox. It needs some patching before we can release it as part of a new release.
See https://app.circleci.com/pipelines/github/sinonjs/fake-timers/117/workflows/625d68b6-ed2c-4d04-a450-c22a240599dd/jobs/670

The "cloud" tests are only run on master, as PR runs can expose the Sauce Labs credentials.

fatso83 · 2021-01-15T15:16:04Z

@benjamingr Do you think you can get this in again, after fixing the issues that broke the build? Was some good work done here by @alistairjcbrown. Shame to let it go to waste.

benjamingr · 2021-01-17T10:36:14Z

Yeah I agree - I just didn't have a ton of free time recently :/

Maybe @itayperry wants to pick up readding this? (I can guide, I just have little free time to dedicate to this myself)

itayperry · 2021-01-22T00:17:43Z

I would be happy to take part in this @benjamingr 🎉
🪴 I could, of course, use some guidance and tips. I hope I'll be able to help 💭

) * Add stack trace to code recursively scheduling timers Use stack information for jobs and timers to provide more context when an infinite loop error is thrown. Fixes #230 Add flag for approaching infinite loop Use a flag when approaching infinite loop detection which will enable an error object to be attached to the job, which can then be used for generating the stack output. Update for PR feedback - Safely update stack property using `defineProperty`, wrapped in try/catch - Tests for more clock functions to confirm stack trace provided - Stack trace slice automatically calculated based on clock function position Remove unnecessary durations and use globals - Use global setInterval and setImmediate to match setTimeout use - Remove unnecessary duration parameter from setImmediate and setImmediate add use of prettier Firefox and Chrome tests pass after RegExp fix Chrome shows stack messages differently, and uses the words: 'at' and 'Object', Firefox does not - that has created two problems: first, the stack trace messages that are shown to the user are a bit different (Firefox always has at least one more line at the start of the stack list - usually internal functions that are not supposed to appear). Second, the RegExp tried to match parts of the strings that only exist in Chrome, failing the Firefox tests) prettier used * small RegExp fix for node env + linting * improving test-coverage statistics * at attempt to ignore certain condition in nyc coverage Co-authored-by: Alistair Brown <[email protected]>

alistairjcbrown mentioned this pull request May 17, 2020

Provide more context on infinites recursion #230

Closed

SimenB reviewed May 17, 2020

View reviewed changes

src/fake-timers-src.js Outdated Show resolved Hide resolved

SimenB requested review from benjamingr and fatso83 May 17, 2020 11:45

alistairjcbrown force-pushed the feature/provide-stack-on-infinites-recursion branch from 9a92f55 to 290426e Compare May 17, 2020 13:20

alistairjcbrown force-pushed the feature/provide-stack-on-infinites-recursion branch from 290426e to 033e9fb Compare May 17, 2020 21:01

benjamingr reviewed May 19, 2020

View reviewed changes

alistairjcbrown force-pushed the feature/provide-stack-on-infinites-recursion branch from 825a19b to 0a5b187 Compare May 20, 2020 21:32

benjamingr approved these changes May 20, 2020

View reviewed changes

alistairjcbrown added 4 commits June 8, 2020 21:23

Add stack trace to code recursively scheduling timers

a6f814b

Use stack information for jobs and timers to provide more context when an infinite loop error is thrown. Fixes sinonjs#230

Add flag for approaching infinite loop

52d6dba

Use a flag when approaching infinite loop detection which will enable an error object to be attached to the job, which can then be used for generating the stack output.

Update for PR feedback

135c6fe

- Safely update stack property using `defineProperty`, wrapped in try/catch - Tests for more clock functions to confirm stack trace provided - Stack trace slice automatically calculated based on clock function position

Remove unnecessary durations and use globals

d95493e

- Use global setInterval and setImmediate to match setTimeout use - Remove unnecessary duration parameter from setImmediate and setImmediate

alistairjcbrown force-pushed the feature/provide-stack-on-infinites-recursion branch from 955361e to d95493e Compare June 8, 2020 20:24

benjamingr merged commit 384f696 into sinonjs:master Jun 8, 2020

alistairjcbrown deleted the feature/provide-stack-on-infinites-recursion branch June 8, 2020 20:33

fatso83 mentioned this pull request Sep 14, 2020

Need new release #337

Closed

benjamingr mentioned this pull request Sep 15, 2020

Revert "Add stack trace to code recursively scheduling timers" #338

Merged

itayperry mentioned this pull request May 1, 2021

Retry - Add stack trace to code recursively scheduling timers #325 #375

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add stack trace to code recursively scheduling timers #325

Add stack trace to code recursively scheduling timers #325

alistairjcbrown commented May 17, 2020 •

edited

Loading

codecov bot commented May 17, 2020 •

edited

Loading

SimenB commented May 17, 2020

SimenB commented May 17, 2020 •

edited

Loading

alistairjcbrown commented May 17, 2020

fatso83 commented May 19, 2020

benjamingr May 19, 2020

benjamingr May 19, 2020

benjamingr May 19, 2020

benjamingr left a comment

benjamingr commented May 19, 2020

alistairjcbrown commented May 19, 2020

alistairjcbrown commented May 20, 2020

benjamingr left a comment

benjamingr commented Jun 6, 2020

alistairjcbrown commented Jun 8, 2020

benjamingr commented Jun 8, 2020

fatso83 commented Sep 14, 2020

fatso83 commented Jan 15, 2021

benjamingr commented Jan 17, 2021

itayperry commented Jan 22, 2021 •

edited

Loading

Add stack trace to code recursively scheduling timers #325

Add stack trace to code recursively scheduling timers #325

Conversation

alistairjcbrown commented May 17, 2020 • edited Loading

Purpose (TL;DR) - mandatory

Solution - optional

Example stack trace from test run

codecov bot commented May 17, 2020 • edited Loading

Codecov Report

SimenB commented May 17, 2020

SimenB commented May 17, 2020 • edited Loading

alistairjcbrown commented May 17, 2020

fatso83 commented May 19, 2020

benjamingr May 19, 2020

Choose a reason for hiding this comment

benjamingr May 19, 2020

Choose a reason for hiding this comment

benjamingr May 19, 2020

Choose a reason for hiding this comment

benjamingr left a comment

Choose a reason for hiding this comment

benjamingr commented May 19, 2020

alistairjcbrown commented May 19, 2020

alistairjcbrown commented May 20, 2020

benjamingr left a comment

Choose a reason for hiding this comment

benjamingr commented Jun 6, 2020

alistairjcbrown commented Jun 8, 2020

benjamingr commented Jun 8, 2020

fatso83 commented Sep 14, 2020

fatso83 commented Jan 15, 2021

benjamingr commented Jan 17, 2021

itayperry commented Jan 22, 2021 • edited Loading

alistairjcbrown commented May 17, 2020 •

edited

Loading

codecov bot commented May 17, 2020 •

edited

Loading

SimenB commented May 17, 2020 •

edited

Loading

itayperry commented Jan 22, 2021 •

edited

Loading