syrusakbary/promise

onResolved handler is called in the same execution context

Closed this issue · 15 comments

It seems to me that current implementation is non-compliant with https://promisesaplus.com/ spec with regard to

2.2.4 Fulfilled or onRejected must not be called until the execution context stack contains only platform code. [3.1].

This manifests in inconsistencies between situations where Promise is resolved immediately (such us during unit-testing with mock data) vs situations where it resolves asynchronously after a while, leading to some bugs in implementation manifesting only after deploying to production.

Consider following toy program with a subtle bug:

import concurrent.futures
import time
executor = concurrent.futures.ThreadPoolExecutor(max_workers=40000);
from promise import Promise

def identity(x):
  #time.sleep(1)
  return x
def promise_something(x):
  return Promise.promisify(executor.submit(identity,x));


print Promise.all([ promise_something(x).then(lambda result: result*x)  for x in [0,1,2,3]]).get()

It is supposed to produce sequence of squares, and indeed when run, it prints:

$ python concurrency_test.py
[0, 1, 4, 9]

But there is a bug lurking in the implementation: the x variable used in list comprehension is bound by reference to the closure of lambda: result*x, not by value, so the code works only because the lambda passed to then() is called synchronously and the current value of x is used. If however, you uncomment the time.sleep(1) line, you will get a different output:

$ python concurrency_test.py
[0, 3, 6, 9]

This time, the same value of x, namely 3 was used for all invocations of the lambda, because that was the value variable x retained after iterating over whole array [0,1,2,3].

This is just a toy example, but the more complicated version of the same bug occurred in real life scenario to me in code like this:

return Promise.all([
    diarize_single_wave(diarizationEngine,pathOfWave).then(lambda result : judge_single_result(path_to_name(pathOfWave),result))
    for pathOfWave in glob.glob(join("input-data","*.wav"))
  ])

and it took me a while to figure out what was wrong, as the problem manifested half the time only (namely when run on a clean working directory, without cached results - in case when I already had some cached results on the disk, the Promise returned immediately masking the bug).

Once again: there is a bug in my program, and I know it. But then there is also the Promieses/A+ spec which clearly states, that the callback should not be called before the current stack completes, which I believe leads to more consistent behavior. The README.md of this project proudly claims "Its fully compatible with the Promises/A+ spec", so I think it is a bug in the implementation of this library.

Hi @qbolec the error you are describing have to do with the locals in python more than the promise implementation.

The following example will work:

import concurrent.futures
import time
executor = concurrent.futures.ThreadPoolExecutor(max_workers=40000);
from promise import Promise

def identity(x):
  time.sleep(1)
  return x
def promise_something(x):
  return Promise.promisify(executor.submit(identity,x));


print Promise.all([ promise_something(x).then((lambda x:lambda result: result*x)(x))  for x in [0,1,2,3]]).get()

This example is encapsulating the x in a new function, so doesn't get overwritten when the next item in the loop is accessed.

You seem to miss the point. I don't want to make my code work. I want to make it fail consistently in testing as it breaks in production. I know where is the bug and how to fix it. The problem is that behavior differs depending on presence of sleep, while it shouldn't according to the spec.

-----Wiadomość oryginalna-----
Od: "Syrus Akbary" notifications@github.com
Wysłano: ‎2016-‎08-‎07 07:16
Do: "syrusakbary/promise" promise@noreply.github.com
DW: "qbolec" qbolec@gmail.com; "Mention" mention@noreply.github.com
Temat: Re: [syrusakbary/promise] onResolved handler is called in the sameexecution context (#9)

Closed #9.

You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.

You're right, I've double checked the spec and did the same example with the native implementation in js and is working in an uniform way.

Here “platform code” means engine, environment, and promise implementation code. In practice, this requirement ensures that onFulfilled and onRejected execute asynchronously, after the event loop turn in which then is called, and with a fresh stack. This can be implemented with either a “macro-task” mechanism such as setTimeout or setImmediate, or with a “micro-task” mechanism such as MutationObserver or process.nextTick. Since the promise implementation is considered platform code, it may itself contain a task-scheduling queue or “trampoline” in which the handlers are called.

However as promise is package external to the Python platform code I don't know how easy will be to make the improvement/fix.

I'm reopening the task, feel free to open a PR if you find a way for making this complaint with the spec for 2.2.4, I will investigate on it as well.

@qbolec I believe #20 will resolve this issue. Can you confirm?

The description of #20 sounds like it should fix it. I could test it and confirm it on Tuesday.

Somehow Github closed the issue automatically, this is still on investigation.

I think a async scheduler/s approach will solve this issue :)

I will post here the results of the benchmarking different scheduling solutions so we can keep track and use the most optimal one (still on the work).

You can also feel free to change the code and run the benchmarks with

pip install -e .[test]
py.test tests/ --benchmark-only

Base (current sync code)

----------------------------------------------------------------------------------------- benchmark: 3 tests ----------------------------------------------------------------------------------------
Name (time in us)                                    Min                   Max               Mean             StdDev             Median                IQR            Outliers(*)  Rounds  Iterations
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
test_benchmark_promise_creation                   7.8678 (1.0)        288.9633 (2.47)      9.9468 (1.0)       4.2215 (1.0)       9.0599 (1.0)       1.1921 (1.0)        1507;2063   20461           1
test_benchmark_promise_creation_with_reject      14.7820 (1.88)       117.0635 (1.0)      17.8837 (1.80)      5.4678 (1.30)     16.9277 (1.87)      1.9073 (1.60)         660;854   11126           1
test_benchmark_promise_creation_with_resolve     19.7887 (2.52)     4,503.0117 (38.47)    27.7827 (2.79)     38.1788 (9.04)     21.2193 (2.34)     11.9209 (10.00)        349;801   16132           1
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Threads (for do_resolve)

------------------------------------------------------------------------------------------ benchmark: 3 tests ------------------------------------------------------------------------------------------
Name (time in us)                                    Min                   Max                Mean              StdDev              Median                IQR            Outliers(*)  Rounds  Iterations
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
test_benchmark_promise_creation                   7.8678 (1.0)        286.1023 (1.0)        9.5521 (1.0)        4.3104 (1.0)        9.0599 (1.0)       0.9537 (1.0)          609;801   12521           1
test_benchmark_promise_creation_with_reject      77.9629 (9.91)       298.0232 (1.04)     110.2021 (11.54)     17.6768 (4.10)     107.0499 (11.82)    20.0272 (21.00)       1589;219    6205           1
test_benchmark_promise_creation_with_resolve     81.0623 (10.30)    5,002.9755 (17.49)    150.0539 (15.71)    103.4804 (24.01)    137.0907 (15.13)    54.8363 (57.50)          56;56    2817           1
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

I'm working in a new branch async-scheduler, that will solve the async issue in a quite performant way.

It's based on the ultra-peformant js library bluebird.
Still a lot of effort to do there, but it's a start point :)

Is the benchmark you posted from my hotfix, where it starts a thread each time? Or is it from the new branch?

If it's the former, do we really want to add that much code to shave what looks like ~150us?

Either way, I'm impressed the number is that low.

Yeah, the benchmark is from your hotfix, where it starts a thread in promise creation.

For the new branch the numbers are actually quite good (median ~ 5us for Promise creation with resolution):

--------------------------------------------------------------------------------------------------- benchmark: 4 tests --------------------------------------------------------------------------------------------------
Name (time in ns)                                        Min                     Max                   Mean                StdDev                 Median                   IQR            Outliers(*)  Rounds  Iterations
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
test_benchmark_promise_creation                     953.6743 (1.0)       87,022.7814 (1.0)       1,240.5232 (1.0)        916.0321 (1.0)         953.6743 (1.0)        238.4186 (1.0)        561;11962   59075           1
test_benchmark_promisify_custom                   1,907.3486 (2.00)     432,968.1396 (4.98)      2,619.7204 (2.11)     2,097.6628 (2.29)      2,145.7672 (2.25)     1,192.0929 (5.00)       3126;3069   99865           1
test_benchmark_promise_creation_with_resolve      3,814.6973 (4.00)     106,096.2677 (1.22)      5,761.5666 (4.64)     2,320.9740 (2.53)      5,006.7902 (5.25)       953.6743 (4.00)       2028;2200   35545           1
test_benchmark_promise_creation_with_reject      13,828.2776 (14.50)    135,183.3344 (1.55)     17,024.3791 (13.72)    5,485.5023 (5.99)     15,020.3705 (15.75)    2,145.7672 (9.00)        935;1919   15421           1
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

And this are the numbers when using threads in the async-dataloader branch:

--------------------------------------------------------------------------------------------------- benchmark: 4 tests ---------------------------------------------------------------------------------------------------
Name (time in ns)                                       Min                       Max                   Mean                 StdDev                Median                   IQR            Outliers(*)  Rounds  Iterations
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
test_benchmark_promise_creation                    953.6743 (1.0)         72,002.4109 (1.0)       1,211.9005 (1.0)         858.1729 (1.0)        953.6743 (1.0)        238.4186 (1.0)       5735;13442   77673           1
test_benchmark_promisify_custom                  1,907.3486 (2.00)       404,834.7473 (5.62)      2,961.7228 (2.44)      3,572.9523 (4.16)     2,861.0229 (3.00)     1,192.0929 (5.00)        641;1204   49933           1
test_benchmark_promise_creation_with_resolve     3,814.6973 (4.00)       195,980.0720 (2.72)      6,367.8546 (5.25)      3,062.5161 (3.57)     5,960.4645 (6.25)     1,907.3486 (8.00)       3182;3166   34664           1
test_benchmark_promise_creation_with_reject      4,768.3716 (5.00)     2,523,899.0784 (35.05)    15,843.8311 (13.07)    46,559.9005 (54.25)    6,198.8831 (6.50)     3,099.4415 (13.00)        131;853    3759           1
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

So overall here's a summary with the current improvements:

  • Promise creation: test_benchmark_promise_creation
    • Non-threading: from 9us to <1us - 10x speed improvement
    • With threads: from 9us to <1us - 10x speed improvement
  • Promise resolution: test_benchmark_promise_creation_with_resolve
    • Non-threading: from 17us to 6us - 3x speed improvement
    • With threads: from 110us to 6us - 20x speed improvement
  • Promise rejection: test_benchmark_promise_creation_with_reject
    • Non-threading: from 21us to 17us - 1.3x speed improvement
    • With threads: from 150us to 15us - 10x speed improvement

Notes

It shouldn't be comparing the master branch. That doesn't have the thread creation.

You should be looking at the pypi branch: https://github.com/p2p-today/promise/tree/pypi

That said, I definitely take back my complaints. 10x speed improvements are nothing to scoff at.

I compared what the PR #20 was requesting, which I think was including the Thread creation... but might be worth to compare it with the pypi branch as well!

Closing this issue, since is solved in master and tested in https://github.com/syrusakbary/promise/blob/master/tests/test_issues.py#L36-L42