syrusakbary / promise

Ultra-performant Promise implementation in Python
MIT License
362 stars 76 forks source link

onResolved handler is called in the same execution context #9

Closed qbolec closed 7 years ago

qbolec commented 8 years ago

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.

syrusakbary commented 8 years ago

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.

qbolec commented 8 years ago

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.

syrusakbary commented 8 years ago

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.

LivInTheLookingGlass commented 7 years ago

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

qbolec commented 7 years ago

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

syrusakbary commented 7 years ago

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

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

syrusakbary commented 7 years ago

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
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
syrusakbary commented 7 years ago

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 :)

LivInTheLookingGlass commented 7 years ago

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.

syrusakbary commented 7 years ago

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
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
syrusakbary commented 7 years ago

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
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
syrusakbary commented 7 years ago

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

Notes

LivInTheLookingGlass commented 7 years ago

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.

syrusakbary commented 7 years ago

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!

syrusakbary commented 7 years ago

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