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

Fix data race in IgnoredMailboxMap #7100

Conversation

stejbac
Copy link
Contributor

@stejbac stejbac commented May 8, 2024

Make the dataMap field of IgnoredMailboxMap a ConcurrentHashMap instead of a HashMap, to prevent a ConcurrentModificationException, which was recently observed when calling IgnoredMailboxMap::toProtoMessage from the persistence manager, inside the user thread during startup of bisq-desktop. Tracing through the code, this likely happened during an iteration through the keyset of dataMap (to check for nulls, inside the proto serialisation logic during persistence), while simultaneously adding ignored mailbox messages to the map on a separate thread spawned from the method, MailboxMessageService::threadedBatchProcessMailboxEntries. (The latter was made asynchronous a long time ago, so as not to block the UI.)

(Since there is a call to PersistenceManager::requestPersistence after every addition to the ignored mailbox map, there hopefully won't be any missed entries in the final persisted map, even though the snapshot of ConcurrentHashMap being iterated through won't be fresh as long as new entries are simultaneously added.)

--

The following intermittent error (which is possibly made more likely by application suspension part way through startup) was last seen in my logs a few weeks ago, during startup of the desktop app, which should hopefully be fixed by this PR:

Apr-16 01:06:57.101 [JavaFX Application Thread] INFO  b.common.persistence.PersistenceManager: Serializing SequenceNumberMap took 143 msec 
Apr-16 01:06:57.207 [Write-SequenceNumberMap_to-disk] INFO  b.common.persistence.PersistenceManager: Writing the serialized SequenceNumberMap completed in 104 msec 
Apr-16 01:06:57.476 [JavaFX Application Thread] INFO  b.common.persistence.PersistenceManager: Serializing UserPayload took 374 msec 
Apr-16 01:06:57.618 [JavaFX Application Thread] INFO  b.common.persistence.PersistenceManager: Serializing MailboxMessageList took 141 msec 
Apr-16 01:06:57.637 [JavaFX Application Thread] ERROR b.common.persistence.PersistenceManager: Error in saveToFile toProtoMessage: IgnoredMailboxMap, IgnoredMailboxMap 
java.util.ConcurrentModificationException
	at java.base/java.util.HashMap$HashIterator.nextNode(HashMap.java:1493)
	at java.base/java.util.HashMap$KeyIterator.next(HashMap.java:1516)
	at com.google.protobuf.MapField$MutatabilityAwareMap.putAll(MapField.java:337)
	at protobuf.IgnoredMailboxMap$Builder.putAllData(IgnoredMailboxMap.java:650)
	at bisq.network.p2p.mailbox.IgnoredMailboxMap.toProtoMessage(IgnoredMailboxMap.java:52)
	at bisq.network.p2p.mailbox.IgnoredMailboxMap.toProtoMessage(IgnoredMailboxMap.java:31)
	at bisq.common.proto.persistable.PersistableEnvelope.toPersistableMessage(PersistableEnvelope.java:30)
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:427)
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:419)
	at bisq.common.persistence.PersistenceManager.lambda$maybeStartTimerForPersistence$8(PersistenceManager.java:407)
	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(Native Method)
	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.gtk.GtkApplication._runLoop(Native Method)
	at com.sun.glass.ui.gtk.GtkApplication.lambda$runLoop$11(GtkApplication.java:277)
	at java.base/java.lang.Thread.run(Thread.java:834)
Apr-16 01:06:57.665 [JavaFX Application Thread] ERROR bisq.common.setup.CommonSetup: Uncaught Exception from thread JavaFX Application Thread 
Apr-16 01:06:57.673 [JavaFX Application Thread] ERROR bisq.common.setup.CommonSetup: throwableMessage= java.util.ConcurrentModificationException 
Apr-16 01:06:57.674 [JavaFX Application Thread] ERROR bisq.common.setup.CommonSetup: throwableClass= class java.lang.RuntimeException 
Apr-16 01:06:57.701 [JavaFX Application Thread] ERROR bisq.common.setup.CommonSetup: Stack trace:
java.lang.RuntimeException: java.util.ConcurrentModificationException
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:441)
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:419)
	at bisq.common.persistence.PersistenceManager.lambda$maybeStartTimerForPersistence$8(PersistenceManager.java:407)
	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(Native Method)
	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.gtk.GtkApplication._runLoop(Native Method)
	at com.sun.glass.ui.gtk.GtkApplication.lambda$runLoop$11(GtkApplication.java:277)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.ConcurrentModificationException
	at java.base/java.util.HashMap$HashIterator.nextNode(HashMap.java:1493)
	at java.base/java.util.HashMap$KeyIterator.next(HashMap.java:1516)
	at com.google.protobuf.MapField$MutatabilityAwareMap.putAll(MapField.java:337)
	at protobuf.IgnoredMailboxMap$Builder.putAllData(IgnoredMailboxMap.java:650)
	at bisq.network.p2p.mailbox.IgnoredMailboxMap.toProtoMessage(IgnoredMailboxMap.java:52)
	at bisq.network.p2p.mailbox.IgnoredMailboxMap.toProtoMessage(IgnoredMailboxMap.java:31)
	at bisq.common.proto.persistable.PersistableEnvelope.toPersistableMessage(PersistableEnvelope.java:30)
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:427)
	... 22 more
 
java.lang.RuntimeException: java.util.ConcurrentModificationException
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:441)
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:419)
	at bisq.common.persistence.PersistenceManager.lambda$maybeStartTimerForPersistence$8(PersistenceManager.java:407)
	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(Native Method)
	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.gtk.GtkApplication._runLoop(Native Method)
	at com.sun.glass.ui.gtk.GtkApplication.lambda$runLoop$11(GtkApplication.java:277)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.util.ConcurrentModificationException
	at java.base/java.util.HashMap$HashIterator.nextNode(HashMap.java:1493)
	at java.base/java.util.HashMap$KeyIterator.next(HashMap.java:1516)
	at com.google.protobuf.MapField$MutatabilityAwareMap.putAll(MapField.java:337)
	at protobuf.IgnoredMailboxMap$Builder.putAllData(IgnoredMailboxMap.java:650)
	at bisq.network.p2p.mailbox.IgnoredMailboxMap.toProtoMessage(IgnoredMailboxMap.java:52)
	at bisq.network.p2p.mailbox.IgnoredMailboxMap.toProtoMessage(IgnoredMailboxMap.java:31)
	at bisq.common.proto.persistable.PersistableEnvelope.toPersistableMessage(PersistableEnvelope.java:30)
	at bisq.common.persistence.PersistenceManager.persistNow(PersistenceManager.java:427)
	... 22 more
Apr-16 01:06:57.873 [Write-MailboxMessageList_to-disk] INFO  b.common.persistence.PersistenceManager: Writing the serialized MailboxMessageList completed in 254 msec 
Apr-16 01:06:57.919 [JavaFX Application Thread] INFO  b.common.persistence.PersistenceManager: Serializing DisputeList took 186 msec 
Apr-16 01:06:58.148 [Write-MediationDisputeList_to-disk] INFO  b.common.persistence.PersistenceManager: Writing the serialized MediationDisputeList completed in 129 msec 
Apr-16 01:06:59.399 [JavaFX Application Thread] INFO  b.common.persistence.PersistenceManager: Serializing ClosedTrades took 1324 msec 
Apr-16 01:07:00.324 [Write-FailedTrades_to-disk] INFO  b.common.persistence.PersistenceManager: Writing the serialized FailedTrades completed in 897 msec 
Apr-16 01:07:02.013 [Write-ClosedTrades_to-disk] INFO  b.common.persistence.PersistenceManager: Writing the serialized ClosedTrades completed in 2614 msec 

stejbac added 2 commits May 8, 2024 17:28
Make the 'dataMap' field a ConcurrentHashMap instead of a HashMap, to
prevent a ConcurrentModificationException, which was recently observed
when calling 'IgnoredMailboxMap::toProtoMessage' from the persistence
manager inside the user thread during startup of bisq-desktop. Tracing
through the code, this likely happened during an iteration through the
keyset of 'dataMap' (to check for nulls, inside the proto serialisation
logic during persistence), while simultaneously adding ignored mailbox
messages to the map on a separate thread spawned from the method,
'MailboxMessageService::threadedBatchProcessMailboxEntries'. (The latter
was made asynchronous so as not to block the UI.)

(Since there is a call to 'PersistenceManager::requestPersistence' after
every addition to the ignored mailbox map, there hopefully won't be any
missed entries in the final persisted map, even though the snapshot of
ConcurrentHashMap being iterated through won't be fresh as long as new
entries are simultaneously added.)
Copy link
Collaborator

@HenrikJannsen HenrikJannsen left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

utACK

Copy link
Contributor

@alejandrogarcia83 alejandrogarcia83 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

utACK

@alejandrogarcia83 alejandrogarcia83 merged commit 3b428df into bisq-network:master May 9, 2024
1 of 3 checks passed
@alejandrogarcia83 alejandrogarcia83 added this to the v1.9.16 milestone May 9, 2024
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 this pull request may close these issues.

3 participants