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

Fix context between two async requests #7

Merged
merged 4 commits into from
Nov 29, 2018

Commits on Nov 20, 2018

  1. Handle context between two async requests

    This commit fixes a bug where a request can end without finishing its
    timings. See: MiniProfiler#4
    
    Bug cause: The structure that is used to register Miniprofiler timing
    providers, like (Postgres, HTTP, Redis), because it overrides the
    original method (globally) and uses the `request` object to access the
    Miniprofiler extensions to build the timings, and this doesn't work in a
    scenario with simultaneous requests using an async provider.
    
    Here is an example using
    [`pg`](https://github.com/goenning/miniprofiler-pg/blob/master/index.js)
    to try illustrating the failing scenario (check out the
    `tests/concurrent-async-test.js` test to see it running).
    
    request A start:
    * `pg.Client.prototype.query` holds a `req` object of requestA.
    * It calls `.query` in a pg instance
      * A miniprofiler timing starts with the call to
        `req.miniprofiler.timeQuery(...)`
      * The original method is called (async).
    
    request B start:
    * `pg.Client.prototype.query` holds a `req` object of request B.
    * It calls `.query` in a pg instance
      * Start timing with `req.miniprofiler.timeQuery(...)`
      * The original method is called (async).
    
    request A resume:
    * The result of `.query` is returned
    * A new call to  `.query` is made
      * This time the `req` points to request B, this means that
        `req.miniprofiler.timeQuery(...)` will start a timing on request B.
      * The original method is called (async)
    
    request B resume:
    * The result of `.query` is returned.
    * All data was fetched, the request is ready to finish, so internally
      Miniprofile calls
      [`stopProfilling`](https://github.com/MiniProfiler/node/blob/1a98e40698b1126ac8de728a33406656361f8870/lib/miniprofiler.js#L80).
      * This fails because there is a timing started (by request A) but not
        finished, so calculating the
        [diffs](https://github.com/MiniProfiler/node/blob/1a98e40698b1126ac8de728a33406656361f8870/lib/miniprofiler.js#L409)
        will fails because `stop` is undefined.
    
    Solution
    --------
    
    Using NodeJS "async_hooks" we can track the reference to the correct
    extension for each request, so calls to `req.miniprofiler.timeQuery()`
    will point to the correct miniprofiler extension.
    
    To check some performance analisys see:
    nodejs/node#14794 (comment)
    
    The goal of the current commit isn't introduce breaking changes, so the
    miniprofiler reference is injected into the request using JS getters.
    
    Another solution is changing the API for providers, where instead of
    receiving a `req` reference, they can receive a function that gets the
    reference to the correct miniprofiler instance. But this will break API
    with all existing providers.
    
    References
    ----------
    
    - https://medium.com/the-node-js-collection/async-hooks-in-node-js-illustrated-b7ce1344111f
    - https://medium.com/@guysegev/async-hooks-a-whole-new-world-of-opportunities-a1a6daf1990a
    - nodejs/node#14794 (comment)
    Danilo Resende committed Nov 20, 2018
    Configuration menu
    Copy the full SHA
    f2d02e4 View commit details
    Browse the repository at this point in the history
  2. Update asyncctx

    Danilo Resende committed Nov 20, 2018
    Configuration menu
    Copy the full SHA
    c39c8a3 View commit details
    Browse the repository at this point in the history
  3. Lock "debug" dependency to work on Node v4

    Koa adds dependency to `"debug": "*"` which fetch a version non
    compatible with Node v4. Locking it on our package.json fix this issue.
    Danilo Resende committed Nov 20, 2018
    Configuration menu
    Copy the full SHA
    44e8197 View commit details
    Browse the repository at this point in the history

Commits on Nov 26, 2018

  1. Drop Node version < 8

    After more testing the 'async-hooks' polyfill shown to not work properly
    for Node version prior to 8.
    Danilo Resende committed Nov 26, 2018
    Configuration menu
    Copy the full SHA
    7f9fa5e View commit details
    Browse the repository at this point in the history