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

Error Task TrustedListenableFutureTask@7d185bf2[status=PENDING, info=[task=[running=[NOT STARTED YET] #6480

Closed
pprvggc6um opened this issue Dec 21, 2022 · 18 comments · Fixed by #6488

Comments

@pprvggc6um
Copy link

Description

Error windows opens with the following text

Error
Task TrustedListenableFutureTask@7d185bf2[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1211/0x000000001fff47c0@2bbeee47]]] rejected from java.util.concurrent.ThreadPoolExecutor@114159ed[Running, pool size = 36, active threads = 36, queued tasks = 10, completed tasks = 125192]

Version

1.9.7

Steps to reproduce

Error appears sometime after application startup

Expected behaviour

Error window should not appear

Actual behaviour

Error window is shown

Screenshots

Device or machine

HP Elitebook 8470p
Windows 7 Pro

Additional info

error log available, but too large to paste into form

@boring-cyborg
Copy link

boring-cyborg bot commented Dec 21, 2022

Thanks for opening your first issue here!

Be sure to follow the issue template. Your issue will be reviewed by a maintainer and labeled for further action.

@ghost
Copy link

ghost commented Dec 21, 2022

@pprvggc6um could you attach the log, or paste the stack trace from the log which is immediately following the ERROR line in the log. 100 or so lines from the log before and after the error might be useful for context also. Thanks

@pprvggc6um
Copy link
Author

bisq.log

@ghost
Copy link

ghost commented Dec 21, 2022

@HenrikJannsen could you look into this?

Dec-21 05:44:27.602 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: Uncaught Exception from thread JavaFX Application Thread 
Dec-21 05:44:27.626 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: throwableMessage= Task TrustedListenableFutureTask@28630e7c[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1211/0x000000001fff47c0@39a9487a]]] rejected from java.util.concurrent.ThreadPoolExecutor@114159ed[Running, pool size = 36, active threads = 36, queued tasks = 10, completed tasks = 99013] 
Dec-21 05:44:27.626 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: throwableClass= class java.util.concurrent.RejectedExecutionException 
Dec-21 05:44:27.626 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: Stack trace:
java.util.concurrent.RejectedExecutionException: Task TrustedListenableFutureTask@28630e7c[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1211/0x000000001fff47c0@39a9487a]]] rejected from java.util.concurrent.ThreadPoolExecutor@114159ed[Running, pool size = 36, active threads = 36, queued tasks = 10, completed tasks = 99013]
    at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.reject(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.execute(Unknown Source)
    at com.google.common.util.concurrent.MoreExecutors$ListeningDecorator.execute(MoreExecutors.java:611)
    at java.base/java.util.concurrent.AbstractExecutorService.submit(Unknown Source)
    at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:66)
    at bisq.network.p2p.network.NetworkNode.sendMessage(NetworkNode.java:294)
    at bisq.network.p2p.peers.BroadcastHandler.sendToPeer(BroadcastHandler.java:241)
    at bisq.network.p2p.peers.BroadcastHandler.lambda$broadcast$0(BroadcastHandler.java:156)
    at bisq.common.reactfx.FxTimer.lambda$restart$0(FxTimer.java:93)
    at com.sun.scenario.animation.shared.TimelineClipCore.visitKeyFrame(TimelineClipCore.java:239)
    at com.sun.scenario.animation.shared.TimelineClipCore.playTo(TimelineClipCore.java:180)
    at javafx.animation.Timeline.doPlayTo(Timeline.java:172)
    at javafx.animation.AnimationAccessorImpl.playTo(AnimationAccessorImpl.java:39)
    at com.sun.scenario.animation.shared.SingleLoopClipEnvelope.timePulse(SingleLoopClipEnvelope.java:103)
    at javafx.animation.Animation.doTimePulse(Animation.java:1186)
    at javafx.animation.Animation$1.lambda$timePulse$0(Animation.java:204)
    at java.base/java.security.AccessController.doPrivileged(Unknown Source)
    at javafx.animation.Animation$1.timePulse(Animation.java:203)
    at com.sun.scenario.animation.AbstractPrimaryTimer.timePulseImpl(AbstractPrimaryTimer.java:343)
    at com.sun.scenario.animation.AbstractPrimaryTimer$MainLoop.run(AbstractPrimaryTimer.java:266)
    at com.sun.javafx.tk.quantum.QuantumToolkit.pulse(QuantumToolkit.java:559)
    at com.sun.javafx.tk.quantum.QuantumToolkit.pulse(QuantumToolkit.java:543)
    at com.sun.javafx.tk.quantum.QuantumToolkit.pulseFromQueue(QuantumToolkit.java:536)
    at com.sun.javafx.tk.quantum.QuantumToolkit.lambda$runToolkit$11(QuantumToolkit.java:342)
    at com.sun.glass.ui.InvokeLaterDispatcher$Future.run(InvokeLaterDispatcher.java:96)
    at com.sun.glass.ui.win.WinApplication._runLoop(Native Method)
    at com.sun.glass.ui.win.WinApplication.lambda$runLoop$3(WinApplication.java:174)
    at java.base/java.lang.Thread.run(Unknown Source)

HenrikJannsen added a commit to HenrikJannsen/bisq that referenced this issue Dec 22, 2022
bisq-network#6480 reported reaching the limit with the current settings.

Signed-off-by: HenrikJannsen <boilingfrog@gmx.com>
@HenrikJannsen
Copy link
Collaborator

HenrikJannsen commented Dec 22, 2022

Hm... surprised that the change caused that error.
We had before corePoolSize=15, maximumPoolSize=30 und capacity for the ArrayBlockingQueue 30.
Now we have corePoolSize=24, maximumPoolSize=36 und capacity 10. So maybe the decrease of the capacity was too much.

Here the PR:
#6481

ripcurlx pushed a commit that referenced this issue Dec 22, 2022
#6480 reported reaching the limit with the current settings.

Signed-off-by: HenrikJannsen <boilingfrog@gmx.com>
@ripcurlx
Copy link
Contributor

@pprvggc6um We just published a new pre-release that should fix this issue: https://github.com/bisq-network/bisq/releases/tag/v1.9.8. Could you please give the version a try if it fixes your problem? Thanks!

@pprvggc6um
Copy link
Author

I loaded the 1.9.8 version that was linked to, and I am still getting a similar error.

Error
Task TrustedListenableFutureTask@10bd2c8[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1627/0x000000001ff53ad8@7204cb88]]] rejected from java.util.concurrent.ThreadPoolExecutor@1db7039e[Running, pool size = 36, active threads = 36, queued tasks = 30, completed tasks = 56619]

@HenrikJannsen
Copy link
Collaborator

HenrikJannsen commented Dec 23, 2022

@pprvggc6um Could you connect normally with the 1.9.6 version?
Maybe your network setup has issues.
Those are the network threads for sending a message or creating a connection and more than 12 is already weird. Your app is using 66 threads. That should never be the case. I have it running since hours and dont see any issue.

@pprvggc6um
Copy link
Author

I didn't see this issue with 1.9.6, or any other 1.9.x version (I have installed and run 1.9.1-8). I haven't made any noticeable change to my usage patterns or system configuration. I have usually have bisq running in the background while using a web browser, text editor, etc.
What sort of network setup issue can I look for?

@ghost
Copy link

ghost commented Dec 24, 2022

This has been reported a couple more times for v1.9.8, namely in #6484 and #6485.

Looking at the logs posted there, the problem seems to start after network issues have prevented P2P messages from being sent; there are 18 consecutive logs of Broadcast did not complete after 120.8 sec. just prior:

Dez.-24 11:11:40.693 [JavaFX Application Thread] WARN  b.n.p.p.BroadcastHandler: Broadcast did not complete after 120.8 sec.
numPeersForBroadcast=6
numOfCompletedBroadcasts=5
numOfFailedBroadcasts=0 
Dez.-24 11:11:46.425 [JavaFX Application Thread] WARN  b.n.p.p.BroadcastHandler: Broadcast did not complete after 120.8 sec.
numPeersForBroadcast=7
numOfCompletedBroadcasts=6
numOfFailedBroadcasts=0 
Dez.-24 11:11:47.893 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: Uncaught Exception from thread JavaFX Application Thread 
Dez.-24 11:11:47.893 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: throwableMessage= Task TrustedListenableFutureTask@39d46180[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1424/0x000000080082f990@7414378]]] rejected from java.util.concurrent.ThreadPoolExecutor@61f270fb[Running, pool size = 36, active threads = 36, queued tasks = 29, completed tasks = 78078] 
Dez.-24 11:11:47.894 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: throwableClass= class java.util.concurrent.RejectedExecutionException 
Dez.-24 11:11:47.897 [JavaFX Application Thread] ERROR b.c.s.CommonSetup: Stack trace:
java.util.concurrent.RejectedExecutionException: Task TrustedListenableFutureTask@39d46180[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1424/0x000000080082f990@7414378]]] rejected from java.util.concurrent.ThreadPoolExecutor@61f270fb[Running, pool size = 36, active threads = 36, queued tasks = 29, completed tasks = 78078]
    at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.reject(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.execute(Unknown Source)
    at com.google.common.util.concurrent.MoreExecutors$ListeningDecorator.execute(MoreExecutors.java:611)
    at java.base/java.util.concurrent.AbstractExecutorService.submit(Unknown Source)
    at com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:66)
    at bisq.network.p2p.network.NetworkNode.sendMessage(NetworkNode.java:294)
    at bisq.network.p2p.peers.BroadcastHandler.sendToPeer(BroadcastHandler.java:241)
    at bisq.network.p2p.peers.BroadcastHandler.lambda$broadcast$0(BroadcastHandler.java:156)

@CygnusGt
Copy link

I am the one from #6484 and like @pprvggc6um I can confirm:
a) that I have not seen this message with 1.9.6 or any previous version.
b) that I have not made any (conscious) changes to my usage or settings.

@13Homer13
Copy link

Same here. Same error since 1.9.8. MacBook Ventura 13.0.1

@HenrikJannsen
Copy link
Collaborator

@pprvggc6um @CygnusGt @13Homer13 Do you get repeated error popups or just one? Does the app behaves normal after closing the error popup?

@CygnusGt
Copy link

CygnusGt commented Dec 27, 2022

@HenrikJannsen :

Do you get repeated error popups or just one?

Until today I got the error popup only once.

Does the app behaves normal after closing the error popup?

Yes, the app behaves normal after closing the error popup.

@HenrikJannsen
Copy link
Collaborator

It seems its a non critical issue and was present also before 1.9.7 but the RejectedExecution was swallowed. It can happen when there are boost of message broadcasting. If it happens the pending send tasks are dropped then. But from one logs it seems that the user got into a deadlock which is of course critical.

But not complete with my investigation....

@CygnusGt
Copy link

I just got the error popup a second time:

Error Task TrustedListenableFutureTask@31549b9e[status=PENDING, info=[task=[running=[NOT STARTED YET], bisq.network.p2p.network.NetworkNode$$Lambda$1837/0x00000008008bf788@52cfb6d7]]] rejected from java.util.concurrent.ThreadPoolExecutor@5f911e9e[Running, pool size = 36, active threads = 36, queued tasks = 30, completed tasks = 71558]

I attach a current log.
bisq_log_2022-12-28.zip

The Bisq app continues to behave normal after closing the error popup.

@pprvggc6um
Copy link
Author

@HenrikJannsen

Do you get repeated error popups or just one?
I have seen anywhere between 1-4 repeating pop ups. I'm not sure, but the number may be related to how long I'm AFK.

Does the app behaves normal after closing the error popup?
After closing the popup, the app does act as expected. Until the next error pops up.

@HenrikJannsen
Copy link
Collaborator

@HenrikJannsen

Do you get repeated error popups or just one? I have seen anywhere between 1-4 repeating pop ups. I'm not sure, but the number may be related to how long I'm AFK.

If that is the case, it seems your network get throttled by the OS when in standby mode. Which OS do you use? On OSX there are some settings in the energy savings section. I think it has differences in each OSX version so cannot really give a suggestion but you can try out to change settings there like 'Enable Power nap' to see if its different.
If you come back from AFK and see a low number of connections (bottom right corner - 12 is normal number of nodes, below 8 is not normal) it is a hint as well that the OS throttle the network.

Does the app behaves normal after closing the error popup? After closing the popup, the app does act as expected. Until the next error pops up.

Yes, as far I saw it is not critical. I added a few fixes and improvements but if the error popups don't come too often we will not make a hotfix release for it, but next release will have it fixed.

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

Successfully merging a pull request may close this issue.

5 participants