Error: Another accept task is ongoing :: JS Native classes making HTTP dispatcher fail.

[andreespirela]

Note: This is a really strange bug, so I would like to ask you for patience while reading it.

[Details]
First, I would like you to see this video because it will be hard to explain with only words:
Click here to see video
I have attached this video in .ZIP format at the end of the issue if you do not feel comfortable with google drive

--
What you saw in this video is that a class with no imports whatsoever (I say this because at first I thought imports were making the HTTP dispatcher fail) is making the http dispatcher fail.
It's been happening to new classes on my code no matter whether it has imports or no as you saw in the video. I have spent more than a day to find the root of the problem in order to be able to record this video.
I can create any class in any folder, and it will make the http dispatcher fail, no matter what the content of the class is.
It is also happening to both static and non-static methods, it is also happening to classes without methods. so if I only import the class and as soon as I call it like this MyClass; (so no effect at all on the code), it will make the HTTP dispatcher fail.

Update: It is happening not only with JS classes, but also empty defaults (export default {}) & functions (export function MyFunction() {}), with any class name, with any method name...

[Context]
It is impossible for me to provide a small context or reproducible context because I do not even know what the context is. It happens randomly to new classes, one class may cause the HTTP dispatcher fail, but another class may work just fine. When finding the causes and playing around with the code, I moved the class you saw in the video to a folder inside a folder inside a folder, and it worked fine, then I got the class out of the folder, and it started failing again: I say this just to demonstrate how random it is.

[Additional]
I have wiped out my DENO_DIR, but it didn't do anything, the error was still being thrown.

I didn't want to open this issue until being sure it was a real issue/bug. As per my conversation with @lucacasonato where I share these same details, we agreed on the weirdness of this.

[Stacktrace]

 Error: Another accept task is ongoing
    at unwrapResponse ($deno$/ops/dispatch_json.ts:42:11)
    at Object.sendAsync ($deno$/ops/dispatch_json.ts:93:10)
    at async ListenerImpl.accept ($deno$/net.ts:63:17)
    at async Server.acceptConnAndIterateHttpRequests (server.ts:212:14)
    at async MuxAsyncIterator.callIteratorNext (mux_async_iterator.ts:30:31)

[Code details]
This is happening in Mandarine Framework. You can find the failing code in the branch make-everything-a-proxy.

1. Download the mentioned branch (make-everything-a-proxy)
2. Go to the root of it in your computer
3. Run deno run --config tsconfig.json --allow-net --allow-read examples/example-1.ts

OrmCoreDecoratorsProxy which is the class that is making the HTTP dispatcher fail at this time, is being called in /orm-core/core/decorators/entityDecorator.ts Line 16. (Inside decorator method "Table")

OrmCoreDecoratorsProxy is located in /orm-core/proxys/ormCoreDecorators.ts

I would like to mention that the decorator Table where the problem is happening as described before is not even being called in the file that's being ran (examples/example-1.ts), so the code is never processing OrmCoreDecoratorsProxy, the very very simple fact of putting it in the code is making the HTTP dispatcher fail somehow.

[OS]
MacOS Mojave 10.14.6

[Environment]
deno 1.1.2
v8 8.5.216
typescript 3.9.2

Update After testing with many versions of Deno, this started happening in version 1.0.3 as it is not happening in 1.0.2

---

cc @lucacasonato

screen-capture (3).webm.zip

[lucacasonato]

I just git bisected this, and this bug was introduced in the TS compiler refactor (ad6d2a7). cc @bartlomieju

Also this is a duplicate of #6301, but this the better issue as it has a more easily reproducible example and better environment information.

[andreespirela]

I have made some progress investigating how to reproduce/ or what's causing the error. As the exception was showing something related to the HTTP dispatcher & an ongoing task, I put the HTTP dispatcher inside a setTimeout of 1ms. that solved the problem ** for now **.

In this screenshot: https://prnt.sc/tbhv6k, you can see the changes I have made.
I turned the method run (responsible for starting the http server through oak) in a non-async method, and I put the app.listen inside the setTimeout which executes an async method.

I did this because my logic was indicating me that it was related to some internal process from Deno taking place so I guessed the setTimeout could help. At first I used setTimeout with 1000ms (1s), then I tested it with 1ms and both worked.

I hope this provides more context as what I did is not an optimal solution nor fixes the bigger problem as it is likely this issue is affecting something else more than an http dispatcher

cc @lucacasonato @bartlomieju

[bartlomieju]

I added some logging to check where's the problem:

listening
before handle request!
server async iter
accept conn and iterate http requests
before
call accept tcp
call accept poll fn
before track task
track task in tcp listener
call accept poll fn
before track task
track task in tcp listener

call accept poll fn is printed twice for single call to Listener.accept() - it seems it wasn't the case before. Nevertheless logic for track_task() seems funky to me - it's perfectly valid and expected that accept future can be polled multiple times - track_task() should account for that.

CC @piscisaureus @ry

[ry]

It would be very helpful for debugging if we had a small repeatable snippet of code. For example, if someone made a copy of @andreespirela's code base, and slowly started removing bits of code that have nothing to do with repeating this bug, all the time ensuring that it still fails - this would get us 90% towards a fix to this bug.

[andreespirela]

@ry I will try to do this on my side, although it has been hard because as I mentioned, I don’t find the right context since everything seems to be aleatory even though it’s not. But I will do my best effort to put some small piece of code together and reproduce this. Hopefully, I will get something.

Cc @lucacasonato @bartlomieju

[bartlomieju]

We've discussed this issue offline and have a candidate for the root cause of the problem. I'll be working on a fix.

[bartlomieju]

@andreespirela this issue should be fixed by #6838 - unfortunately due to unversioned imports I am not able to run provided branch on latest Deno. Would you mind updating it?

[andreespirela]

Thank you!. I will be updating the branch throughout the day and will let you know.

[lucacasonato]

@andreespirela Is this issue fixed?

[andreespirela]

@lucacasonato As far as I have tested, it is. It's been a pain to use the initial branch I mentioned on this ticket because of many changes I have made along with the upgrades from Deno, but with current branches and current versions of Mandarine this has not happened anymore. initially, I had a setTimeout as a quickfix for the HTTP dispatcher to work

When the bug was happening, commenting out the setTimeout would cause Mandarine to fail while the modules were loaded, right now, I'm not using any setTimeout and Mandarine keeps working just fine

[lucacasonato]

I will close because it seems like it was fixed.

[irustm]

This very strange bug has been haunting me for about six months...

And it is still not fixed. It starts to appear very unpredictable! Today's working code may not start in a week! It is primarily related to import.
I wrote about it in discord, but nobody turned to this bug.
it starts to appear only if import is added to one part of the code
https://github.com/alosaur/alosaur/runs/1045800710?check_suite_focus=true

error: Uncaught Busy: Another accept task is ongoing
    at unwrapResponse (rt/10_dispatch_json.js:24:13)
    at sendAsync (rt/10_dispatch_json.js:75:12)
    at async Listener.accept (rt/30_net.js:114:19)
    at async Server.acceptConnAndIterateHttpRequests (server.ts:212:14)
    at async MuxAsyncIterator.callIteratorNext (mux_async_iterator.ts:30:31)

[andreespirela]

This very strange bug has been haunting me for about six months...

And it is still not fixed. It starts to appear very unpredictable! Today's working code may not start in a week! It is primarily related to import.
I wrote about it in discord, but nobody turned to this bug.
it starts to appear only if import is added to one part of the code
https://github.com/alosaur/alosaur/runs/1045800710?check_suite_focus=true

error: Uncaught Busy: Another accept task is ongoing
    at unwrapResponse (rt/10_dispatch_json.js:24:13)
    at sendAsync (rt/10_dispatch_json.js:75:12)
    at async Listener.accept (rt/30_net.js:114:19)
    at async Server.acceptConnAndIterateHttpRequests (server.ts:212:14)
    at async MuxAsyncIterator.callIteratorNext (mux_async_iterator.ts:30:31)

What's your environment?
Deno version, typescript, v8, etc. It would be really useful if you can offer more details, I agree this is a very strange and unpredictable bug.

[irustm]

I tried it on minimal code, but the error can only appear when there is a lot of import

perhaps it also has something to do with decorators.

just like that

deno --version                                                                                         
deno 1.3.2
v8 8.6.334
typescript 4.0.2

[andreespirela]

I tried it on minimal code, but the error can only appear when there is a lot of import

perhaps it also has something to do with decorators.

just like that

deno --version                                                                                         
deno 1.3.2
v8 8.6.334
typescript 4.0.2

This is right, initially it happened to me with including a decorator in the code. Can you please provide a video or do a deeper investigation on when it happens, how it happens, take a look at the video I first attached, and see my first comment on this bug, let's see if you can reproduce something similar and see if we can get something out of it

[irustm]

As I have noticed it depends primarily on the amount of import and export in the code. https://youtu.be/i1ZYFvHtiYg.

[qbytx]

I am having the same issue, and its almost identical to what @irustm showed in the video. I.e., Too many exports in my dep.ts file (i.e., my dependencies file)

My environment is Win10, Deno 1.3.0 on E: drive, local install of postgresql on E: drive
I can't use the latest version of deno because it's currently incompatible with 0.4.3 of the postgresql driver.
(If they would just get around to pushing 0.4.4., i saw they fixed the issue)

The hacky solution is to break your dependency files into smaller chunks. That seems to work for me so far.

So now I have:

dep_0.ts
dep_1.ts

and split my exports between them.

this works, but its obviously not expected behavior

Prior to doing this, I just had one file called dep.ts which contained this:

export { dirname, join } from "https://deno.land/[email protected]/path/mod.ts";

export { createError } from "https://deno.land/x/[email protected]/mod.ts";

export { opine, json, urlencoded, serveStatic, Router } from "https://deno.land/x/[email protected]/mod.ts";

export { Request, Response, NextFunction } from "https://deno.land/x/[email protected]/src/types.ts";

export { renderFileToString } from "https://deno.land/x/[email protected]/mod.ts";

export { acceptWebSocket, acceptable } from "https://deno.land/std/ws/mod.ts";

//export { Client } from "https://deno.land/x/postgres/mod.ts"; 
// If I include this last line, I get 'Another accept task is ongoing"

See Last line ^

So to reiterate, this was my solution:

(in my app.ts file)

import {
  dirname,
  join,
  createError,
  opine,
  json,
  urlencoded,
  serveStatic,
  Response,
  Request,
  NextFunction,
  renderFileToString
} from "./dep_0.ts";

import 
{
  Client
} from "./dep_1.ts";

[bartlomieju]

I believe this is most likely caused by bug in TLA - tracked in #6616

[bartlomieju]

I believe this is most likely caused by bug in TLA - tracked in #6616

Should have been fixed in #7946 - will be available in 1.5.0 in two weeks.

[andreespirela]

As 1.5.0 was released today, after some testing, I can't manage to reproduce it. I don't know if this is because a fix as suggested by @bartlomieju or the possible nature of the bug.

I'm highly on the side that it was fixed, but I can't feel certain.

[lucacasonato]

Let's close it then and consider it fixed. If it does pop up again at, we can reopen the issue.