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

occasional mvn spring-boot:run failures with ServiceException / TaskRejectedException #9785

Closed
vlukashov opened this issue Jan 11, 2021 · 11 comments · Fixed by #9915
Closed

Comments

@vlukashov
Copy link

vlukashov commented Jan 11, 2021

Occasionally starting a Vaadin project in the dev mode fails with a stack trace like below. The exception is typically gone after restating the app (mvn spring-boot:run) or clearing the project (mvn clean).

There was an unexpected error (type=Internal Server Error, status=500).
org.springframework.core.task.TaskRejectedException: Executor [java.util.concurrent.ThreadPoolExecutor@4c28451b[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]] did not accept task: java.util.concurrent.CompletableFuture$UniWhenComplete@1d1cbb67
com.vaadin.flow.server.ServiceException: org.springframework.core.task.TaskRejectedException: Executor [java.util.concurrent.ThreadPoolExecutor@4c28451b[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]] did not accept task: java.util.concurrent.CompletableFuture$UniWhenComplete@1d1cbb67
	...
Caused by: org.springframework.core.task.TaskRejectedException: Executor [java.util.concurrent.ThreadPoolExecutor@4c28451b[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]] did not accept task: java.util.concurrent.CompletableFuture$UniWhenComplete@1d1cbb67
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:324)
	at java.base/java.util.concurrent.CompletableFuture$UniCompletion.claim(CompletableFuture.java:568)
	at java.base/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:850)
	at java.base/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:837)
	at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
	at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1742)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	... 1 more
Caused by: java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.CompletableFuture$UniWhenComplete@1d1cbb67 rejected from java.util.concurrent.ThreadPoolExecutor@4c28451b[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 0]
	at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2055)
	at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:825)
	at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1355)
	at org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor.execute(ThreadPoolTaskExecutor.java:321)
	... 8 more

more context: https://vaadin.slack.com/archives/CDNTYMS9H/p1608663499135200

@taefi
Copy link
Contributor

taefi commented Jan 13, 2021

@vlukashov Thanks for creating the issue.
Would you please add some details about the context, environment, versions, etc., and any possible steps to help us reproduce it?

@vlukashov
Copy link
Author

vlukashov commented Jan 13, 2021

All the details we currently have are in the linked Slack thread. Unfortunately, there are no clear steps to reproduce the issue at the moment, but it has appeared for several people more than once.

@Artur-
Copy link
Member

Artur- commented Jan 19, 2021

The exception originates in https://github.com/vaadin/flow/blob/master/flow-server/src/main/java/com/vaadin/flow/server/DevModeHandler.java#L261

and I guess it originates from the Spring Boot application being shut down during startup.

The log seems to at least most of the time contain something like

2021-01-19 14:52:20.457  INFO 77677 --- [         task-1] c.v.f.s.frontend.TaskUpdatePackages      : Frontend dependencies resolved successfully.
2021-01-19 14:52:20.466  INFO 77677 --- [         task-1] c.v.f.s.frontend.TaskCopyFrontendFiles   : Copying frontend resources from jar files ...
2021-01-19 14:52:20.530  INFO 77677 --- [       Thread-5] o.s.s.concurrent.ThreadPoolTaskExecutor  : Shutting down ExecutorService 'applicationTaskExecutor'
{spring.web.resources.chain.cache=false, spring.web.resources.cache.period=0}

@denis-anisimov
Copy link
Contributor

The question is : is it the expected behavior of Spring/web app or not?

o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService 'applicationTaskExecutor'

The expected behavior based on this line : Spring is shutting down.
So it doesn't matter whether there is a subsequent exception or not: it jus says that the task can't be executed which is not a problem since it doesn't matter. The app is stopped anyway.

So :

  • this is either a bug in Spring (why it shuts down itself during the startup) ?
  • something wrong with the app itself (so that it makes this happen : for some reason the app is stopped)
  • or this is "expected" behavior (well, it's Spring: who knows why it stop itself during startup ?) and one more workaround should be invented to be ready for such behavior (and I can't imagine what can be done here).

So (hopefully) the exception is not the cause of this behavior. The reason might be the stop of the application during its startup and this is should be investigated.

@Artur-
Copy link
Member

Artur- commented Jan 19, 2021

After the message, the app is started again but webpack dev server is never started again.
I think you can reproduce this by e.g. compiling a file during startup -> spring boot devtools will kick in and restart. Just need to compile it at the correct time

@denis-anisimov
Copy link
Contributor

OK, so this is "expected" behavior.
I refrain from commenting this.

@pleku
Copy link
Contributor

pleku commented Jan 21, 2021

The reason might be the stop of the application during its startup and this is should be investigated.

Apparently something happens (guesses are that IDE recompilation or something else, touching something in target) that triggers the spring boot to restart, not shutdown. And in the code we have this is detected to be the same as SB shutting down - and stopping the webpack devserver without starting it again. So basically SB dev tools triggered restart occurs "during/immediately after server startup" and causes webpack devserver to never be started.

So to reproduce this one can try getting a v19 SB app from SVC and then

  • start the app and during the startup touch something that should trigger a reload by SB devtools
  • use VSCode and trying to get it to recompile automatically during server startup

If this only occurs with VSCode users then it would be low impact indeed, but as until we've figured that out, this as this is happening with the default stack should be considered high impact instead. And as there is a workaround (clean/restart), it is not a blocker but I don't see how it would be only minor either.

@Artur-
Copy link
Member

Artur- commented Jan 21, 2021

I can reproduce it like this:

npx @vaadin/cli init --pre taskrejected
cd taskrejected
echo "vaadin.pnpm.enable=false" >> src/main/resources/application.properties
mvn &

When Running 'npm install' to resolve and optionally download frontend dependencies has been logged, run

touch target/classes/com/example/application/Application.class

After this, when you open localhost:8080 you will see the standard "The frontend development build has not yet finished. Please wait..." until "npm install" has finished. After that, the exception is shown

If you run it multiple times, be sure to delete node_modules before running mvn

Note1: It is not the webpack dev server process that is interrupted, it is npm install
Note2: It is easier to reproduce with npm instead of pnpm but likely unrelated

@pleku
Copy link
Contributor

pleku commented Jan 25, 2021

The plan is to revert the fix for vaadin/spring#691 on the /flow side as it is not deemed nearly as high impact/severity issue as this one. That should fix this issue but needs to be validated (before revert merge). Then we reopen the other issue and come back to it to fix it in another way that does not cause this to reappear.

@taefi taefi self-assigned this Jan 27, 2021
@Artur-
Copy link
Member

Artur- commented Jan 27, 2021

To me it looks like only a logic problem in DevModeHandler. If I read it correctly the logic goes like this:

  1. Some preqrequisite task is passed to DevModeHandler (in practice the "npm install" task)
  2. DevModeHandler waits for the prereq task to complete and then runs webpack
  3. If the prereq task fails, then webpack running is reported as failed with the same exception
  4. If webpack running failed, it is never retried. Not even after Spring Boot redeploys

If npm install fails, then the webpack dev server should not be run. This work fine.

The problem is that it is marked as a permanent error instead of just not running webpack, and when asked to start webpack again it would try again.

@denis-anisimov
Copy link
Contributor

denis-anisimov commented Jan 27, 2021

To me it looks like only a logic problem in DevModeHandler.

No it's not.

The problem is in Spring.
Executor service is provided as a managed bean from Spring.

This service is the only problem here.
Before fix for mvn spring-boot:start mvn spring-boot:stop case there was single threaded non Spring managed Excecutor used.
And everything worked fine because there is no need to retry anything.
The only reason of prerequisite failure was : it's not possible to install packages and this is not recoverable problem.

Spring dev tools introduced unexpected problem : now every task may be simply cancelled: BOTH tasks (npm install or dev mode start taksk)
There was no any reason to assume that cancelation may happen unless JVM is stopped.

Spring dev tools completely destroy all beans and recreates them.
Executor is a managed Disposable Spring bean. It's destroyed and can't be reused EVER after that.
Moreover Lookup instance which is passed to a CTOR of DevModeHandler is created based on ApplicationContext which also should be destroyed by Spring dev tools and recreated.
So you may not simply use Executor from Lookup as is here: it's stopped and won't accept any new task for execution.

All these things are caused by Spring and dev tools.

It is not possible to fix this simply. The proper fix requires serious changes in Spring add-on and most likely here.
Spring dev tools breaks all the assumptions which was made to design DevModeHandler.

To avoid any unexpected Spring behavior the easiest way to revert the fix for mvn spring-boot:start mvn spring-boot:stop and redo it after that properly taking into account all Spring surprises (but I'm too optimistic here).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants