Move to async/await. Get rid of callback hell #3540

muxator · 2019-01-16T23:20:01Z

Currently (1.8pre), Etherpad code base is heavily based on callbacks. While this made sense at the time (~2011) JS ecosystem has moved forward, and better solutions exist.

We should investigate the possibility of migrating the code base to an async/await paradigm, in order to make the code easier on the eye of future contributors.

This move was anticipated in #3424. It is now time to start discussing it concretely.

As usual, the first concern is maintaining stability: this change is going to be wide, but should be as shallow as possible, ideally not containing any new functionality work. After this, hopefully the code base will be easier to reason about, less buggy, and new features will be easier to implement.

Edit: the Pull Request that implements this change is #3559.

The text was updated successfully, but these errors were encountered:

raybellis · 2019-01-16T23:29:29Z

I plan to investigate this - I'll look into it and report back in a few days.

raybellis · 2019-01-23T09:28:55Z

I'm working on this at https://github.com/raybellis/etherpad-lite/tree/async

muxator · 2019-02-05T21:32:03Z

Ray has completed the fist stage of his amazing work at https://github.com/raybellis/etherpad-lite/tree/async.

The review is being done at https://github.com/raybellis/etherpad-lite/tree/async-PR. That branch is a linear variant of Ray's work, rebased on the latest develop, on which some adaptation are being made.

async-PR is a mutable branch, i.e. it will be periodically force-pushed until it is ready to be merged.

muxator · 2019-02-08T11:49:42Z

Branch raybellis/async-PR is now deployed on https://beta.etherpad.org/ to allow widespread testing.

It will be periodically updated while the branch is audited.

raybellis · 2019-02-08T17:36:21Z

Please note that I've added a couple of extra commits to the async branch which relate to import and export.

muxator · 2019-02-09T02:40:42Z

Thanks, imported.

I am (slowly) going through the series, trying to:

separate out purely syntactic changes from substantial ones (to ease later review and catch eventual bugs)
split changes where possible (for example https://github.com/raybellis/etherpad-lite/commit/2075e6fd6acda938d605cc4f94c8522f342c4a8e in async contained a condition inversion and the part that strictly introduced promises consumption, so they can be examined separately.

This will take some time.

Wikinaut · 2019-02-19T11:30:06Z

Clarification request/question:

From the above I understand that the branch https://github.com/raybellis/etherpad-lite/tree/async-PR is now stable enough to try and test it on own instances.

Is my view correct?

muxator · 2019-02-19T11:47:25Z

Hi @Wikinaut, yes please, test as much as you can. Any info is welcome to help polishing this branch.
As soon as https://beta.etherpad.org/ comes back online it will host that branch, too.

@raybellis: is it possible to write here a brief list of known issues, if any?

Next version will be Etherpad 1.8. As planned in #3424, we are going to require NodeJS >=8.9.0 and npm >= 6.4. This commit implements that change and updates documentation and scripts. Subsequent changes will get rid of old idioms, dating back to node < 0.7, that still survive in the code. Once migrated to NodeJS 8, we will be able to start working on migrating the code base from callbacks to async/await, greatly simplifying legibility (see #3540). Closes #3557

raybellis · 2019-02-21T00:07:37Z

@muxator The only issue I'm currently aware of is a possible problem (to be confirmed) with importing ".etherpad" format files.

muxator · 2019-02-21T22:48:04Z

Yeah, the .etherpad export needs to be investigated.
Both on beta (which uses mysql) and locally (dirtydb) I am receiving authorEntry is not defined in ExportEtherpad.js.

[2019-02-21 22:43:06.969] [ERROR] console - (node:16064) UnhandledPromiseRejectionWarning: ReferenceError: authorEntry is not defined
    at Object.exports.getPadRaw (/home/etherpad-lite/etherpad-lite/src/node/utils/ExportEtherpad.js:49:41)
    at process._tickCallback (internal/process/next_tick.js:68:7)

BTW, I am frequently seeing another "author-related" error both in the beta and locally:

Error: Can't apply USER_CHANGES, because Trying to submit changes as another author in changeset Z:i>1|1=h*0|1+1$
    at handleUserChanges ([...]/src/node/handler/PadMessageHandler.js:638:13)
    at <anonymous>

raybellis · 2019-02-22T11:02:47Z

The first one is easily fixed (commit c5a633d in my async branch). I don't know what I was thinking there, but the double assignment of authorEntry is clearly incorrect.

The second one is going to require more investigation. padMessageHandler was one of the harder modules to convert, and I expect this bug only becomes evident if there are multiple users editing a pad.

raybellis · 2019-02-22T12:31:17Z

I can't see how to replicate the USER_CHANGES issue - do you have some of the preceding log messages?

muxator · 2019-02-22T19:18:00Z

A recap of the issues so far:

problem in .etherpad export.
Fixed by Ray and integrated in async-PR, also depolyed on https://beta.etherpad.org. It works now;
~~problem in .etherpad import. Succintly, importing an .etherpad file seems not to have any effect~~.
Fixed in the async-PR branch deleting a let statement as explained in comments to https://github.com/raybellis/etherpad-lite/commit/af0a276fbaeddc4027d892bca514201d01ea0e86#diff-55dbdbca4a859fc5f879f68721f70cbcR30

after closer investigation, importing an .etherpad file seems to corrupt the DB (dirtydb in my case). It can be tested importing an .etherpad file, and then immediately shutting down and restarting the Etherpad instance. It will not start, writing this message:

[2019-02-23 00:13:35.243] [WARN] console - DirtyDB is used. This is fine for testing but not recommended for production. File location: <basedir>/var/dirty.db
events.js:183
      throw er; // Unhandled 'error' event
      ^

 Error: Could not load corrupted row: {"val":{"atext":{"text":"SOMETEXT","attribs":"*0|1+7|1+1"},"pool":{"numToAttrib":{"0":["author","a.D1eRFPomtKec121x"]},"nextNum":1},"head":3,"chatHead":-1,"publicStatus":false,"passwordHash":null,"savedRevisions":[]}}
    at <basedir>/src/node_modules/dirty/lib/dirty/dirty.js:165:30
    at Array.forEach (<anonymous>)
    at ReadStream.<anonymous> (<basedir>/src/node_modules/dirty/lib/dirty/dirty.js:152:11)
    at emitOne (events.js:116:13)
    at ReadStream.emit (events.js:211:7)
    at addChunk (_stream_readable.js:263:12)
    at readableAddChunk (_stream_readable.js:246:13)
    at ReadStream.Readable.push (_stream_readable.js:208:10)
    at onread (fs.js:2050:12)
    at callback (<basedir>/src/node_modules/npm/node_modules/graceful-fs/polyfills.js:128:19)

Fixed with the previous remediation (removing a let statement). Upon restart the DB is no longer corrupt.
This, however, uncovers another bug, explained at point 5.

sometimes a user change gets rejected with Can't apply USER_CHANGES, because Trying to submit changes as another author in changeset XXX at handleUserChanges (PadMessageHandler.js). This is present in beta (logs are not verbose there), and I personally experienced it locally. I will try to describe a simple case to replicate it.
right after importing an .etherpad file (and on each visualization of the pad thereafter), this error pops up:
```
[2019-02-23 00:49:58.388] [ERROR] message - There is no author for authorId: a.D1eRFPomtKec121x
```

muxator · 2019-02-22T23:43:34Z

I think I found the problem with .etherpad import, it should be a scope problem.

Removing a let statement as explained in comments to https://github.com/raybellis/etherpad-lite/commit/af0a276fbaeddc4027d892bca514201d01ea0e86#diff-55dbdbca4a859fc5f879f68721f70cbcR30 should be enough.

I have committed the change in async-PR branch at https://github.com/raybellis/etherpad-lite/commit/b69f1c6afc253c1d14e066889acb598d76e13ece. This commit will be folded with the preceding one.

The fix uncovers another possible bug. Details in #3540 (comment) to keep everything in a single palce.

Wikinaut · 2019-02-26T11:20:21Z

[UPDATE: this is solved now in a newer branch]

@raybellis @muxator I have now setup my test server using raybellis/async 39b0c7e (and before, I tried, raybellis/async-PR https://github.com/raybellis/etherpad-lite/commit/4bf1a434d44c792850bb643a9b2c04d78c65af42 ) branch.

Both branches currently fail to load a page. Let me know, when you have some news.

...
[2019-02-26 12:14:37.352] [INFO] ueberDB - Flushed 5 values
[2019-02-26 12:14:43.990] [ERROR] console - { inspect: [Function: inspect] }
[2019-02-26 12:14:45.576] [INFO] ueberDB - Flushed 1 values
...
[2019-02-26 12:14:45.677] [INFO] ueberDB - Flushed 1 values
[2019-02-26 12:14:45.911] [INFO] access - [ENTER] Pad "test": Client kFv_Vbak0IPr100-AAAA with IP "127.0.0.1" entered the pad
[2019-02-26 12:14:45.913] [ERROR] console - (node:1489) UnhandledPromiseRejectionWarning: ReferenceError: newVars is not defined
    at handleClientReady (/srv/etherpad/src/node/handler/PadMessageHandler.js:1132:28)
    at processTicksAndRejections (internal/process/next_tick.js:81:5)
[2019-02-26 12:14:45.914] [ERROR] console - (node:1489) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
[2019-02-26 12:14:45.914] [ERROR] console - (node:1489) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
[2019-02-26 12:14:45.984] [INFO] ueberDB - Flushed 1 values

raybellis · 2019-02-26T14:08:00Z

@Wikinaut thanks for the report - fixed in commit f8a26cb in my async branch

muxator · 2019-02-26T20:15:57Z

Integrated in async-PR with the original change that touched SecurityManager.js and some related functions (ee03456#diff-5d2aa4336c4964b828a123e20e09b73cR1230), and deployed on beta.

I never encountered that error, btw. Thanks to @Wikinaut's testing.

Wikinaut · 2019-02-26T22:26:13Z

@raybellis Confirmed, f8a26cb works! Thank you.

I see one error:

2019-02-26 23:23:23.066] [INFO] ueberDB - Flushed 1 values
[2019-02-26 23:23:26.081] [ERROR] console - { inspect: [Function: inspect] }
...
[2019-02-26 23:23:28.681] [INFO] ueberDB - Flushed 1 values
[2019-02-26 23:23:29.045] [INFO] access - [ENTER] Pad "test": Client AlC0RET9-mC4OmtLAAAA with IP "XXX" entered the pad
[2019-02-26 23:23:29.987] [INFO] ueberDB - Flushed 1 values
[2019-02-26 23:23:32.428] [WARN] console - Getting pad email stuff for test
[2019-02-26 23:23:32.431] [WARN] console - padId is test
...
[2019-02-26 23:23:32.993] [INFO] ueberDB - Flushed 3 values

Wikinaut · 2019-02-26T22:30:20Z

And I see

[ERROR] console - (node:3464)
[DEP0096] DeprecationWarning: timers.unenroll() is deprecated.
Please use clearTimeout instead.

This Error is also present in the callback version.

muxator · 2019-02-27T00:41:35Z

And I see
[ERROR] console - (node:3464)
[DEP0096] DeprecationWarning: timers.unenroll() is deprecated.
Please use clearTimeout instead.
This Error is also present in the callback version.

I think this is #3472.

Wikinaut · 2019-02-27T11:39:37Z

I am now checking the compatibility with my plugins; I will present a list of the working plugins soon, but this

https://npmjs.org/package/ep_small_list

is not working, perhaps @raybellis can you have a look, why "small_list" appears not to work with the async branch?

raybellis · 2019-02-28T09:40:48Z

@Wikinaut I'll take a look, but my suspicion is that 1.8 will be incompatible with most (if not all) existing plugins because none of the exposed functions take a final callback parameter any more. For those, a simple solution is to use the nodeify module to turn a Promise-based API back into a NodeJS style callback(err, result) one.

See, for example, the way that channels.channels is now invoked in line 63 of src/node/handler/PadMessageHandler.js.

muxator · 2019-02-28T09:49:23Z

This is probably worh a dedicated issue.

@raybellis, could you open one with a brief description so we can keep track of it?

[edit]: the issue regarding dealing with plugin compatibility was opened by Ray at #3566. A possible solution is 4fdc73cdc47829fcb19f3e82c878a5f94e00f0d, which as of 2019-03-03 is still not integrated into async-PR because I did not understand if it is definitive or not.

Wikinaut · 2019-02-28T09:56:54Z

Are you interested in the list of my plugins which run (on the async version) without apparent issues?

raybellis · 2019-02-28T10:53:09Z

@Wikinaut that would be useful, but on the other ticket (#3566) please.

raybellis · 2019-03-01T12:23:03Z

Back-end test failures with the SessionManager on the async branches were mentioned (and resolved) at #3567 (comment)

muxator · 2019-03-07T09:24:17Z

It's done. See #3559 (comment).

muxator added the stale code label Jan 16, 2019

muxator mentioned this issue Feb 5, 2019

skins: the "custom" dir will disappear and may disorient users #3498

Closed

muxator added this to the 1.8 milestone Feb 8, 2019

muxator pinned this issue Feb 8, 2019

This was referenced Feb 18, 2019

For Etherpad 1.7, require node 6.9. Since 1.8, require node 8.9 minimum #3424

Closed

chatandusers in colibris skin #3548

Closed

colibris: no colors for names in chat #3549

Closed

Require Nodejs >= 8.9 #3557

Closed

muxator mentioned this issue Feb 21, 2019

Migrate from callbacks to async/await #3559

Merged

raybellis mentioned this issue Feb 28, 2019

Async API changes may break plugins #3566

Closed

muxator added the async-migration Migration from callback-style programming to async functions label Feb 28, 2019

muxator closed this as completed in 4c45ac3 Mar 7, 2019

muxator mentioned this issue Mar 7, 2019

Fix freeze on pad deletion #3562

Merged

muxator unpinned this issue Mar 7, 2019

muxator mentioned this issue May 2, 2019

eejs is using blocking API :: Wont fix as it doesn't actually effect performance noticably. #642

Closed

muxator mentioned this issue Nov 26, 2019

UnhandledPromiseRejectionWarning when using Etherpad remotely #3645

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Move to async/await. Get rid of callback hell #3540

Move to async/await. Get rid of callback hell #3540

muxator commented Jan 16, 2019 •

edited

Loading

raybellis commented Jan 16, 2019

raybellis commented Jan 23, 2019

muxator commented Feb 5, 2019 •

edited

Loading

muxator commented Feb 8, 2019

raybellis commented Feb 8, 2019

muxator commented Feb 9, 2019

Wikinaut commented Feb 19, 2019

muxator commented Feb 19, 2019

raybellis commented Feb 21, 2019

muxator commented Feb 21, 2019

raybellis commented Feb 22, 2019 •

edited

Loading

raybellis commented Feb 22, 2019

muxator commented Feb 22, 2019 •

edited

Loading

muxator commented Feb 22, 2019 •

edited

Loading

Wikinaut commented Feb 26, 2019 •

edited

Loading

raybellis commented Feb 26, 2019

muxator commented Feb 26, 2019

Wikinaut commented Feb 26, 2019

Wikinaut commented Feb 26, 2019

muxator commented Feb 27, 2019

Wikinaut commented Feb 27, 2019

raybellis commented Feb 28, 2019 •

edited

Loading

muxator commented Feb 28, 2019 •

edited

Loading

Wikinaut commented Feb 28, 2019

raybellis commented Feb 28, 2019

raybellis commented Mar 1, 2019

muxator commented Mar 7, 2019

Move to async/await. Get rid of callback hell #3540

Move to async/await. Get rid of callback hell #3540

Comments

muxator commented Jan 16, 2019 • edited Loading

raybellis commented Jan 16, 2019

raybellis commented Jan 23, 2019

muxator commented Feb 5, 2019 • edited Loading

muxator commented Feb 8, 2019

raybellis commented Feb 8, 2019

muxator commented Feb 9, 2019

Wikinaut commented Feb 19, 2019

muxator commented Feb 19, 2019

raybellis commented Feb 21, 2019

muxator commented Feb 21, 2019

raybellis commented Feb 22, 2019 • edited Loading

raybellis commented Feb 22, 2019

muxator commented Feb 22, 2019 • edited Loading

muxator commented Feb 22, 2019 • edited Loading

Wikinaut commented Feb 26, 2019 • edited Loading

raybellis commented Feb 26, 2019

muxator commented Feb 26, 2019

Wikinaut commented Feb 26, 2019

Wikinaut commented Feb 26, 2019

muxator commented Feb 27, 2019

Wikinaut commented Feb 27, 2019

raybellis commented Feb 28, 2019 • edited Loading

muxator commented Feb 28, 2019 • edited Loading

Wikinaut commented Feb 28, 2019

raybellis commented Feb 28, 2019

raybellis commented Mar 1, 2019

muxator commented Mar 7, 2019

muxator commented Jan 16, 2019 •

edited

Loading

muxator commented Feb 5, 2019 •

edited

Loading

raybellis commented Feb 22, 2019 •

edited

Loading

muxator commented Feb 22, 2019 •

edited

Loading

muxator commented Feb 22, 2019 •

edited

Loading

Wikinaut commented Feb 26, 2019 •

edited

Loading

raybellis commented Feb 28, 2019 •

edited

Loading

muxator commented Feb 28, 2019 •

edited

Loading