8266421: Deadlock in Sound System #4141

mrserb · 2021-05-21T08:15:25Z

In the fix for JDK-8207150 I have updated the synchronization of some code paths under one "lock", before that code was synchronized only on some threads and missing on others. Old review:
http://mail.openjdk.java.net/pipermail/sound-dev/2018-August/000650.html

That fix introduced this order of locks: "lock"->"synchronized(this)", I have checked other places and did not found where we use the opposite order. Unfortunately, one such place exists in the private subclass DirectClip.

I have checked both usages of synchronized which caused deadlock:

In the DirectClip class the method setMicrosecondPosition is marked as "synchronized" but it is unclear why. This method is implemented as a call to another public method setFramePosition which is not "synchronized" and use some internal synchronization. So I have removed this keyword.
In a few places we have the code like this:

        boolean sendEvents = false;
        synchronized (this) {
            if (this.started != started) {
                this.started = started;
                sendEvents = true;
            }
	}
        if (sendEvents) {.....

I doubt that this type of synchronization may help something - the fields are volatile and we use sendEvents flag after synchronisation block, so I removed it as well. Any thoughts?

Progress

Change must not contain extraneous whitespace
Commit message must refer to an issue
Change must be properly reviewed

Issue

JDK-8266421: Deadlock in Sound System

Reviewers

Phil Race (@prrace - Reviewer)
Alexander Zvegintsev (@azvegint - Reviewer)

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/4141/head:pull/4141
$ git checkout pull/4141

Update a local copy of the PR:
$ git checkout pull/4141
$ git pull https://git.openjdk.java.net/jdk pull/4141/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 4141

View PR using the GUI difftool:
$ git pr show -t 4141

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/4141.diff

bridgekeeper · 2021-05-21T08:16:33Z

👋 Welcome back serb! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

openjdk · 2021-05-21T08:18:27Z

@mrserb The following labels will be automatically applied to this pull request:

2d
sound

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing lists. If you would like to change these labels, use the /label pull request command.

mrserb · 2021-05-21T08:21:46Z

/remove label 2d

openjdk · 2021-05-21T08:22:47Z

@mrserb Unknown command remove - for a list of valid commands use /help.

mrserb · 2021-05-21T08:23:56Z

/label remove 2d

openjdk · 2021-05-21T08:24:22Z

@mrserb
The 2d label was successfully removed.

mlbridge · 2021-05-21T19:17:20Z

Webrevs

01: Full - Incremental (2025e14a)
00: Full (aedecbf4)

azvegint · 2021-05-24T12:16:15Z

src/java.desktop/share/classes/com/sun/media/sound/AbstractDataLine.java

+        if (this.started != started) {
+            this.started = started;


I doubt that this type of synchronization may help something - the fields are volatile and we use sendEvents flag after synchronization block, so I removed it as well. Any thoughts?

These fields are volatile, but the comparison and assignment is not atomic.
So I believe it is possible the case when we will have sendEvents == true in two threads, hence we will send a duplicate event.

So we probably might want to use AtomicBoolean if you want to get rid of synchronized.

It could make sense only if the "sendEvents" flag will be used under some kind of synchronization as well, otherwise, it is possible to get sendEvents=true twice, it was not changed after this fix:
synchronized (this) {
if (this.started != started) {
this.started = started;
sendEvents = true;
}
}
<<< here the other thread could set "started" to the opposite state and we post events twice.
if (sendEvents) {
.....
}

The case with setting opposite state you are describing is a different one. We will post two different events like start and stop.

I am talking about calling setStarted() with same parameter from different threads.

For example we have two threads T1 and T2 calling setStarted(true).
Before the fix only one of thread will set sendEvents to true due to synchronized block.

After the fix following is possible:

// this.started == false, started == true if (this.started != started) { //T1 passed this check // <<<<< at this moment T2 checks the statement above this.started = started; // T1 and T2 assigns same new value to this.started sendEvents = true; // both threads sets sendEvents to true. } // sending two start events.

My example was about the thread-safety of the method, after synchronized block, the other thread may change the state, then post event, and then this thread will post event. So we will post the event twice in the wrong order. So this method as-is is not thread-safe, we should not call it in parallel. I'll post data for its usage here.

The changes in the AbstractDataLine.setActive() are fine, we do not post events there.

The changes in the AbstractDataLine.setStarted() are used and syncronised:
used in AbstractDataLine:343- the setEOM() dead unused non-public method
used in AbstractDataLine:205 - syncronised on synchronized(mixer); Also dead code, the setStarted() is never executed, since the line is stopped already a few lines above in the implStop();
used in DirectAudioDevice:533 - synchronized on synchronized(lock) and synchronized(mixer)
used in DirectAudioDevice:560 - synchronized on synchronized(lock) and synchronized(mixer)
used in DirectAudioDevice:707 - synchronized on synchronized(lock)
used in DirectAudioDevice:932 - synchronized on synchronized(lock)

The changes in the AbstractLine.setOpen() are used and synchronised:
used in AbstractDataLine:118 - syncronised on synchronized(mixer);
used in AbstractDataLine:374 - syncronised on synchronized(mixer);
used in AbstractMixer:288 - syncronised on this;
used in AbstractMixer:377 - syncronised on this;
used in PortMixer:277 - syncronised on synchronized(mixer);
used in PortMixer:293 - syncronised on synchronized(mixer);

So every object uses its own high-level synchronization when it calls the methods in question.

azvegint · 2021-05-24T12:23:55Z

test/jdk/javax/sound/sampled/Clip/SetPositionHang.java

+            System.out.println("Thread " + thread + " Play "
+                                       + System.currentTimeMillis() % 100000);


This println spams a lot.
It took a ~1 second less to complete the test when these lines are commented(~8s vs ~9s, I believe it will took more on slower machines).
So we probably could comment out these lines to reduce test execution time.

The test is updated.

openjdk · 2021-06-06T00:13:12Z

@mrserb This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8266421: Deadlock in Sound System

Reviewed-by: prr, azvegint

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 230 new commits pushed to the master branch:

8130be5: 8268318: Missing comma in copyright header
b09d8b9: 8267926: AsyncLogGtest.java fails on assert with: decorator was not part of the decorator set specified at creation.
5ebd419: 8267972: Inline cache cleaning is not monotonic
6d1f3ac: 8149138: [javadoc] Fix SerialFormBuilder eliminate String bashing
58bdabc: 8268164: Adopt cast notation for WorkerThread conversions
9fc914b: 8204686: Dynamic parallel reference processing support for Parallel GC
908aca2: 8262891: Compiler implementation for Pattern Matching for switch (Preview)
3e48244: 8268301: Closed test: compiler/c2/6371167/Test.java fails after JDK-8267904
204b492: 8267703: runtime/cds/appcds/cacheObject/HeapFragmentationTest.java crashed with OutOfMemory
2aeeeb4: 8268279: gc/shenandoah/compiler/TestLinkToNativeRBP.java fails after LibraryLookup is gone
... and 220 more: https://git.openjdk.java.net/jdk/compare/9eaa4afc99b09f4704e4d641f95104be40b9ea66...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

mrserb · 2021-06-09T00:13:52Z

/integrate

openjdk · 2021-06-09T00:15:09Z

@mrserb Since your change was applied there have been 270 commits pushed to the master branch:

bcaa2cb: 8264144: Add handling of "--about-url" CLI parameter for RPM/DEB packages
ae16052: 8268088: Clarify Method::clear_jmethod_ids() related comments in ClassLoaderData::~ClassLoaderData()
5ad4a91: 8268127: Shenandoah: Heap size may be too small for region to align to large page size
7a37816: 8264866: Remove unneeded WorkArounds.isAutomaticModule
51e8201: 8267764: jpackage cannot handle window screensaver files when EXE renamed as SCR
f9b593d: 8266748: Move modifiers code to Signatures.java
4dd0e7e: 8259806: Clean up terminology on the "All Classes" page
dc6c96b: 8263468: New page for "recent" new API
fafc4d9: 8268352: Rename javadoc Messager class to JavadocLog
b568e87: 8237388: serviceability/dcmd/framework/VMVersionTest.java fails with connection refused error.
... and 260 more: https://git.openjdk.java.net/jdk/compare/9eaa4afc99b09f4704e4d641f95104be40b9ea66...master

Your commit was automatically rebased without conflicts.

Pushed as commit f6f82c3.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.

mrserb added 3 commits May 20, 2021 23:39

Create SetPositionHang.java

a852f51

Update SetPositionHang.java

9f36487

Initial fix

aedecbf

openjdk bot added 2d client-libs-dev@openjdk.org sound client-libs-dev@openjdk.org labels May 21, 2021

openjdk bot removed the 2d client-libs-dev@openjdk.org label May 21, 2021

mrserb marked this pull request as ready for review May 21, 2021 19:11

openjdk bot added the rfr Pull request is ready for review label May 21, 2021

azvegint reviewed May 24, 2021

View reviewed changes

Update SetPositionHang.java

2025e14

prrace approved these changes Jun 6, 2021

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Jun 6, 2021

azvegint approved these changes Jun 7, 2021

View reviewed changes

openjdk bot closed this Jun 9, 2021

openjdk bot added integrated Pull request has been integrated and removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Jun 9, 2021

mrserb deleted the JDK-8266421 branch June 9, 2021 00:17

mrserb mentioned this pull request Dec 15, 2021

8266421: Deadlock in Sound System openjdk/jdk11u-dev#719

Closed

3 tasks

8266421: Deadlock in Sound System #4141

8266421: Deadlock in Sound System #4141

mrserb commented May 21, 2021 •

edited by openjdk bot

bridgekeeper bot commented May 21, 2021

openjdk bot commented May 21, 2021

mrserb commented May 21, 2021

openjdk bot commented May 21, 2021

mrserb commented May 21, 2021

openjdk bot commented May 21, 2021

mlbridge bot commented May 21, 2021 •

edited

azvegint May 24, 2021

mrserb May 25, 2021

azvegint May 25, 2021

mrserb May 26, 2021

mrserb Jun 4, 2021

azvegint May 24, 2021

mrserb Jun 4, 2021

openjdk bot commented Jun 6, 2021 •

edited

mrserb commented Jun 9, 2021

openjdk bot commented Jun 9, 2021

		System.out.println("Thread " + thread + " Play "
		+ System.currentTimeMillis() % 100000);

8266421: Deadlock in Sound System #4141

8266421: Deadlock in Sound System #4141

Conversation

mrserb commented May 21, 2021 • edited by openjdk bot

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented May 21, 2021

openjdk bot commented May 21, 2021

mrserb commented May 21, 2021

openjdk bot commented May 21, 2021

mrserb commented May 21, 2021

openjdk bot commented May 21, 2021

mlbridge bot commented May 21, 2021 • edited

Webrevs

azvegint May 24, 2021

Choose a reason for hiding this comment

mrserb May 25, 2021

Choose a reason for hiding this comment

azvegint May 25, 2021

Choose a reason for hiding this comment

mrserb May 26, 2021

Choose a reason for hiding this comment

mrserb Jun 4, 2021

Choose a reason for hiding this comment

azvegint May 24, 2021

Choose a reason for hiding this comment

mrserb Jun 4, 2021

Choose a reason for hiding this comment

openjdk bot commented Jun 6, 2021 • edited

mrserb commented Jun 9, 2021

openjdk bot commented Jun 9, 2021

mrserb commented May 21, 2021 •

edited by openjdk bot

mlbridge bot commented May 21, 2021 •

edited

openjdk bot commented Jun 6, 2021 •

edited