JDK-4487735 : AWT Event Thread Thrashing (Performance)
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 1.4.0
  • Priority: P3
  • Status: Closed
  • Resolution: Duplicate
  • OS: solaris_8
  • CPU: sparc
  • Submitted: 2001-08-03
  • Updated: 2013-11-01
  • Resolved: 2001-09-17
Related Reports
Relates :  
Description
Profile data from the JMol application shows the AWT event thread starting and stopping several times during startup.  This could be affecting startup time.  Here are some comments from "Danila A. Sinopalnikov".

-------------------------------
I looked at JMol and investigated this issue.

AWT auto-shutdown behavior is based on the following rules:

1.A new blocking thread is created if currently there is no blocking
  thread and one of the following happens:
    (1)The AWT Toolkit is initialized.
    (2)An AWT component peer is created.
    (3)A native event occurs on the native event queue.
    (4)A java event occurs on a java event queue.

2.A new event dispatch thread is started whenever there is no event
  dispatch thread currently associated with an AWT event queue and an
  event appears on the queue.

3.The existing blocking thread terminates all event dispatch threads and
  exits whenever all three conditions are true:
    (5)There are no non-disposed peers.
    (6)There are no events in the native event queue.
    (7)There are no events in java event queues.

I run JMol on Solaris 2.8 with merlin b73:
 % java -server -Xint -Xprof -cp jmol-0.2/jars/jmol.jar -Djmol.home=jmol-0.2 jmol.Jmol

AWT-Shutdown starts up and shuts down 16 times during Jmol startup. 
Each time one of (1)-(4) occurs and after some delay (5)-(7) become true. 
The start reasons are:
(1) - once
(2) - once
(3) - once
(4) - 13 times

AWT-EventQueue-0 starts up and shuts down 13 times during Jmol startup:
1.A java event is posted to an AWT event queue (12 times)
2.A native event occurs on the native event queue (once)

I attached corresponding stack traces at the end of the email.

Every startup and shutdown is performed according to the rules 1-3.
During development of AWT auto shutdown the issue of numerous startups
of blocking threads was taken into account. 
The following solution was to resolve it: termination is initiated 
only when (5)-(7) remain true for a certain timeout (set to 1000ms).
So in any case a blocking thread should live for at least 1000ms.

However, this doesn't work as can be seen from AWT-Shutdown threads
life time in the Xprof output for Jmol startup attached to your
original email. 

I debugged the code and verified that termination starts even if 
(5)-(7) remain true for less than 10ms. 

The behavior doesn't change if the value of the timeout is increased,
say up to 10000ms.

The investigation shows that Object.wait(long delay) wakes up
before the delay elapsed even without the Object being notify()'ed.

I applied the following diffs to AWTAutoShutdown:
--- AWTAutoShutdown.java	Thu Aug  2 13:16:29 2001
***************
*** 278,284 ****
                              break;
                          }
                          timeoutPassed = true;
!                         mainLock.wait(SAFETY_TIMEOUT);
                      }
                  }
              } catch (InterruptedException e) {
--- 278,289 ----
                              break;
                          }
                          timeoutPassed = true;
!                         final long timeout = 
!                             System.currentTimeMillis() + SAFETY_TIMEOUT;
!                         while (timeoutPassed && 
!                                (System.currentTimeMillis() < timeout)) {
!                             mainLock.wait(SAFETY_TIMEOUT);
!                         }

If Object.wait(long delay) works as specified by javadoc,
this change is equivalent, since 'timeoutPassed' is set to 'false'
whenever the 'mainLock' is notified. However, this change noticeably
affects the behavior: AWT-Shutdown starts up only 3 times and
AWT-EventQueue-0 starts up only twice. I was unable to reproduce the
described incorrect behavior of Object.wait(long delay) with a simple
test case and i cannot dig into Object.wait(long delay), since 
Hotspot VM sources are unavailable.

Probably, we should ask Hotspot team to look into this.
If if is impossible, the diffs listed above can be used as a temporary
workaround.
What do you think?

Thanks,
Danila.
----------------------------------------

Comments
EVALUATION Commit to fix in merlin-beta2 (performance - startup). eric.hawkes@eng 2001-08-03 See Comments for Danila's explanation of why we would like some investigation by the VM team. eric.hawkes@eng 2001-08-05 At the request of the merlin engineering manager, I am changing the category to hotspot. The VM team is requested to look into the issue of spurious wakeups. eric.hawkes@eng 2001-08-06 Danila, please make a run on S8 with -XX:-UseLWPSynchronization. If the problem still exists, it's an AWT problem. Thanks, laurie.tolson@east 2001-08-08 Danila is out of town for the next two weeks. Perhaps the hotspot team could test this. eric.hawkes@eng 2001-08-08 Please provide path to jmol application Thanks gary.collins@East 2001-08-09 I attached the results as asked for foo1.out with without flag, default JDK and foo2.out is generated with -XX:-UseLWPSynchronization gary.collins@East 2001-08-09 According to the VM team's investigation, the thread is being notified. Commit to fix in merlin (startup time). eric.hawkes@eng 2001-08-10 Name: dsR10078 Date: 09/03/2001 I run jmol on Sparc/Solaris 8 with merlin b77. The problem is not reproducible with -XX:-UseLWPSynchronization. Without -XX:-UseLWPSynchronization each shutdown of AWT-Shutdown thread follows a spurious wakeup (wait(1000) wakes up without notify() within less than 20ms). With -XX:-UseLWPSynchronization there are no spurious wakeups and AWT-Shutdown thread shuts down only when the app exits. Reassigning back to hotspot. ###@###.### 2001-09-03 ======================================================================
03-09-2001