: 200000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 63
SIGTERM 1
total: 64

syscall seconds calls errors
pause .00 64 64
ioctl .01 176
poll .01 178
sigprocmask .08 972
context .18 711
gettimeofday .08 484
setitimer .00 118
                ---- --- ---
sys totals: .36 2703 64
usr time: .12
elapsed: 10.18
[Minimum alarm interval set to 20000 usecs]
[Minimum AWT input thread polling interval set to 200000 usecs]
Listening on port 34736
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 20000
Awt input thread poll interval: 200000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 67
SIGTERM 1
total: 68

syscall seconds calls errors
pause .03 67 67
ioctl .06 172
poll .01 173
sigprocmask .16 984
context .06 723
gettimeofday .05 477
setitimer .01 119
                ---- --- ---
sys totals: .38 2715 67
usr time: .10
elapsed: 9.98
[Minimum alarm interval set to 20000 usecs]
[Minimum AWT input thread polling interval set to 200000 usecs]
Listening on port 34734
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 20000
Awt input thread poll interval: 200000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 70
SIGTERM 1
total: 71

syscall seconds calls errors
pause .00 70 70
ioctl .06 176
poll .00 181
sigprocmask .15 1034
context .18 758
gettimeofday .09 500
setitimer .01 128
                ---- --- ---
sys totals: .49 2847 70
usr time: .08
elapsed: 10.13
[Minimum alarm interval set to 40000 usecs]
[Minimum AWT input thread polling interval set to 150000 usecs]
Listening on port 34731
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 40000
Awt input thread poll interval: 150000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 82
SIGTERM 1
total: 83

syscall seconds calls errors
pause .02 81 81
ioctl .06 208
poll .01 209
sigprocmask .25 1184
context .07 870
gettimeofday .07 573
setitimer .04 143
                ---- --- ---
sys totals: .52 3268 81
usr time: .16
elapsed: 10.13
[Minimum alarm interval set to 40000 usecs]
[Minimum AWT input thread polling interval set to 150000 usecs]
Listening on port 34725
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 40000
Awt input thread poll interval: 150000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 72
SIGTERM 1
total: 73

syscall seconds calls errors
pause .02 72 72
ioctl .04 220
poll .02 221
sigprocmask .09 1154
context .20 840
gettimeofday .09 589
setitimer .02 136
                ---- --- ---
sys totals: .48 3232 72
usr time: .08
elapsed: 10.04
[Minimum alarm interval set to 20000 usecs]
[Minimum AWT input thread polling interval set to 150000 usecs]
Listening on port 34723
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 20000
Awt input thread poll interval: 150000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 82
SIGTERM 1
total: 83

syscall seconds calls errors
pause .01 82 82
ioctl .03 228
poll .01 229
sigprocmask .18 1236
context .20 906
gettimeofday .19 617
setitimer .00 147
                ---- --- ---
sys totals: .62 3445 82
usr time: .10
elapsed: 10.13
[Minimum alarm interval set to 20000 usecs]
[Minimum AWT input thread polling interval set to 150000 usecs]
Listening on port 34721
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 20000
Awt input thread poll interval: 150000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 69
SIGTERM 1
total: 70

syscall seconds calls errors
pause .02 69 69
ioctl .08 228
poll .05 231
sigprocmask .24 1170
context .09 849
gettimeofday .07 610
setitimer .00 132
                ---- --- ---
sys totals: .55 3289 69
usr time: .08
elapsed: 10.05
[Minimum alarm interval set to 40000 usecs]
[Minimum AWT input thread polling interval set to 100000 usecs]
Listening on port 34719
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 40000
Awt input thread poll interval: 100000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 99
SIGTERM 1
total: 100

syscall seconds calls errors
pause .03 99 99
ioctl .07 300
poll .00 301
sigprocmask .17 1545
context .21 1128
gettimeofday .08 793
setitimer .02 179
                ---- --- ---
sys totals: .58 4345 99
usr time: .13
elapsed: 10.13
Listening on port 34676
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: default
Awt input thread poll interval: default
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 157
SIGTERM 1
total: 158

syscall seconds calls errors
pause .01 146 146
ioctl .22 536
poll .01 541
sigprocmask .42 2629
context .50 1907
gettimeofday .22 1396
setitimer .03 297
                ---- --- ---
sys totals: 1.41 7452 146
usr time: .21
elapsed: 10.15
We have been doing Java performance testing on Solaris
2.4 for x86. We have noticed that in the "idle" steady state,
javavm eats up about 15-20% of the CPU on a 75Mhz Pentium machine.

Running vmstat shows that the number of system calls per second (sy)
increases by 1000 every time you add a javavm to the system,
and reduces by 1000 every time you remove a javavm from the
system.

I noticed bugid 1199087 that seems to show the same symptoms
as we are seeing, except that the javavm is running off the
browser. But this bug is closed.

Is there any way to reduce the overhead of javavm in
the "idle" state?

Customer reports that this is not fixed by JDK 1.1.
I have reproduced this on Solaris 2.5.1 on an SS20 running JDK 1.0.2

Note, removing the "Toolkit.getDefaultToolkit()" call fixes the problem.
Basically just waking the AWT thread up seams to kick us into a mode of
doing at least 700 system calls per second.

TEST CASE BEGIN
import java.awt.*;
import java.io.IOException;
import java.net.ServerSocket;

public class TestAccept {

public static void main( String argvp[] ) {

ServerSocket ss;

Toolkit.getDefaultToolkit();

try {

ss = new ServerSocket( 0 );
System.out.println( "Listening on port " + ss.getLocalPort() );

while( true ) {

System.out.println( "Waiting on connection..." );
ss.accept();

}

}
catch ( IOException e ) {
System.err.println( e + "Error accepting connections" );
System.exit( 1 );
}

}

}
TEST CASE END

Excerpt of truss output while running this program...

ioctl(8, FIONREAD, 0x81536A7C) = 0
gettimeofday(0x81536678) = 0
poll(0x8153464C, 1, 0) = 0
gettimeofday(0x81536678) = 0
gettimeofday(0x815368BC) = 0
poll(0x81534890, 1, 0) = 0
gettimeofday(0x815368BC) = 0
gettimeofday(0x81536874) = 0
getcontext(0x81536DE8)
setcontext(0x812A1DE8)
gettimeofday(0x812A1CAC) = 0
setitimer(ITIMER_REAL, 0x812A1C98, 0x00000000) = 0
getcontext(0x812A1DE8)
setcontext(0x812C3DE8)
setcontext(0x812C3AE4)
    Received signal #14, SIGALRM, in pause() [caught]
pause() Err#91 ERESTART
getcontext(0x812C3DE8)
setcontext(0x812A1DE8)
gettimeofday(0x812A1CAC) = 0
setitimer(ITIMER_REAL, 0x812A1C98, 0x00000000) = 0
getcontext(0x812A1DE8)
setcontext(0x81536DE8)
poll(0x81534890, 1, 0) = 0
gettimeofday(0x815368BC) = 0
getcontext(0x81536DE8)
setcontext(0x81558DE8)
ioctl(8, FIONREAD, 0x81558A9C) = 0
ioctl(8, FIONREAD, 0x81558A9C) = 0
gettimeofday(0x81558698) = 0
poll(0x8155666C, 1, 0) = 0
gettimeofday(0x81558698) = 0
getcontext(0x81558DE8)
setcontext(0x81536DE8)
ioctl(8, FIONREAD, 0x81536A7C) = 0
ioctl(8, FIONREAD, 0x81536A7C) = 0
gettimeofday(0x81536678) = 0
poll(0x8153464C, 1, 0) = 0
gettimeofday(0x81536678) = 0
gettimeofday(0x815368BC) = 0
poll(0x81534890, 1, 0) = 0
gettimeofday(0x815368BC) = 0
gettimeofday(0x81536874) = 0
getcontext(0x81536DE8)
setcontext(0x812A1DE8)
gettimeofday(0x812A1CAC) = 0
setitimer(ITIMER_REAL, 0x812A1C98, 0x00000000) = 0
getcontext(0x812A1DE8)
setcontext(0x812C3DE8)
setcontext(0x812C3AE4)
    Received signal #14, SIGALRM, in pause() [caught]
pause() Err#91 ERESTART
getcontext(0x812C3DE8)
setcontext(0x812A1DE8)
gettimeofday(0x812A1CAC) = 0
setitimer(ITIMER_REAL, 0x812A1C98, 0x00000000) = 0
getcontext(0x812A1DE8)
setcontext(0x81536DE8)
poll(0x81534890, 1, 0) = 0
gettimeofday(0x815368BC) = 0
getcontext(0x81536DE8)
setcontext(0x81558DE8)
ioctl(8, FIONREAD, 0x81558A9C) = 0
ioctl(8, FIONREAD, 0x81558A9C) = 0
gettimeofday(0x81558698) = 0
poll(0x8155666C, 1, 0) = 0
gettimeofday(0x81558698) = 0
getcontext(0x81558DE8)
setcontext(0x81536DE8)
ioctl(8, FIONREAD, 0x81536A7C) = 0
ioctl(8, FIONREAD, 0x81536A7C) = 0
gettimeofday(0x81536678) = 0
poll(0x8153464C, 1, 0) = 0
gettimeofday(0x81536678) = 0
gettimeofday(0x815368BC) = 0
poll(0x81534890, 1, 0) = 0
gettimeofday(0x815368BC) = 0
gettimeofday(0x81536874) = 0
getcontext(0x81536DE8)
setcontext(0x812A1DE8)
gettimeofday(0x812A1CAC) = 0
setitimer(ITIMER_REAL, 0x812A1C98, 0x00000000) = 0
getcontext(0x812A1DE8)
setcontext(0x812C3DE8)
setcontext(0x812C3AE4)
    Received signal #14, SIGALRM, in pause() [caught]
pause() Err#91 ERESTART
getcontext(0x812C3DE8)
setcontext(0x812A1DE8)
gettimeofday(0x812A1CAC) = 0



darin.carlson@Eng 1997-05-07
Additional info to go with the suggested fix that was just added.

From ###@###.### Mon Apr 14 15:33:41 1997
Subject: Java virtual machine performance

Well, at long last the changes and tests are complete.

All indications are that the real problem is in the awt input thread polling
interval. The AWT input loop calls select() with a timeout. This select()
call is translated into a non-blocking call by the io manager in the virtual
machine, as is all blocking io. This is required to implement io in multiple
application level threads ( green threads ). This internal select results in
two non-blocking selects being issued for every call, and these selects seem
to be the primary source of the excessive system calls we've been seeing.

At any rate, in order to test this, I have made modifications in two components
of the virtual machine. One in the main clock manager (source file itimer.c)
and one in the AWT input loop (source file awt_MToolkit.c). These routines now
check environment variables to determine how often to "poll".

The clock manager schedules alarms for any thread wishing to sleep for a
specified period. The minimum allowable sleep time is, by default, 1000
microseconds. With the changes, the environment variable
"JDK_MIN_ALARM_INTERVAL" can be set to the minimum number of microseconds that
will be allowed for any sleep.

Additionally, the AWT input loop now reads the environment variable
"AWT_POLL_INTERVAL" to determine the timeout for it's select (again in
microseconds). The default for this loop is (and was) 50,000 microseconds.

In general, increasing the input loop polling interval has a more significant
impact than increasing the alarm interval on the test application, as well as
on more complex applications tested. This seems reasonable, because, as yet,
we have not been doing a lot of multithreaded i/o, most of the work is in the
AWT thread. The optimal parameters could change, depending on the thread mix
of the applications. Since all i/o polling rates are based on the alarm clock
polling rate (see src file iomgr.c), it may be desirable to add another level
of granularity that allows direct control over i/o polling behavior.

I have attached the JVM source files that have changed. The changes can be
quickly identified by searching for "Burkett" in the source. I have also
included output of various system call counts (truss -c) for different values
of the polling intervals, as well as the java source for the test program that
generated these values. Finally, if it's of any value, I've included the
script I used to run my test cases...

--------------------------------
Steven Burkett
Edward Jones Information Systems
(314) 515-4311


Additional test case info and performance test results.

import java.awt.*;
import java.io.IOException;
import java.net.ServerSocket;

public class TestAccept {

public static void main( String argvp[] ) {

ServerSocket ss;

Toolkit.getDefaultToolkit();

try {

ss = new ServerSocket( 0 );
System.out.println( "Listening on port " +
ss.getLocalPort() );

while( true ) {

System.out.println( "Waiting on connection..."
);
ss.accept();

}

}
catch ( IOException e ) {
System.err.println( e + "Error accepting connections" );
System.exit( 1 );
}

}

}


#!/bin/ksh
 
minclock=$1
awtclock=$2

if [ -z "$minclock" ] ; then
minclock="default"
else
export JDK_MIN_ALARM_INTERVAL=$minclock ;
fi

if [ -z "$awtclock" ] ; then
awtclock="default"
else
export AWT_POLL_INTERVAL=$awtclock
fi
 
java TestAccept&
java_pid=$!
 
sleep 17
 
echo "Starting truss..."
echo
echo '*******************************************'
echo
echo "Minimum clock resolution: $minclock "
echo "Awt input thread poll interval: $awtclock "
uname -a
echo
echo '*******************************************'
echo
 
truss -c -p $java_pid &
 
sleep 10
 
kill $java_pid

[Minimum alarm interval set to 40000 usecs]
[Minimum AWT input thread polling interval set to 100000 usecs]
Listening on port 34716
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 40000
Awt input thread poll interval: 100000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 99
SIGTERM 1
total: 100

syscall seconds calls errors
pause .07 99 99
ioctl .10 296
poll .03 299
sigprocmask .28 1551
context .14 1132
gettimeofday .12 792
setitimer .01 181
                ---- --- ---
sys totals: .75 4350 99
usr time: .14
elapsed: 10.07
[Minimum alarm interval set to 20000 usecs]
[Minimum AWT input thread polling interval set to 100000 usecs]
Listening on port 34714
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 20000
Awt input thread poll interval: 100000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 100
SIGTERM 1
total: 101

syscall seconds calls errors
pause .02 101 101
ioctl .04 324
poll .19 327
sigprocmask .14 1638
context .25 1192
gettimeofday .07 856
setitimer .01 190
                ---- --- ---
sys totals: .72 4628 101
usr time: .07
elapsed: 10.13
[Minimum alarm interval set to 20000 usecs]
[Minimum AWT input thread polling interval set to 100000 usecs]
Listening on port 34703
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 20000
Awt input thread poll interval: 100000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 105
SIGTERM 1
total: 106

syscall seconds calls errors
pause .01 104 104
ioctl .09 316
poll .01 318
sigprocmask .15 1646
context .27 1201
gettimeofday .18 841
setitimer .01 194
                ---- --- ---
sys totals: .72 4620 104
usr time: .14
elapsed: 10.14
[Minimum alarm interval set to 10000 usecs]
[Minimum AWT input thread polling interval set to 100000 usecs]
Listening on port 34701
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 10000
Awt input thread poll interval: 100000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 106
SIGTERM 1
total: 107

syscall seconds calls errors
pause .02 101 101
ioctl .08 324
poll .05 327
sigprocmask .22 1670
context .20 1217
gettimeofday .08 859
setitimer .03 195
                ---- --- ---
sys totals: .68 4693 101
usr time: .09
elapsed: 10.15
[Minimum alarm interval set to 10000 usecs]
[Minimum AWT input thread polling interval set to 100000 usecs]
Listening on port 34699
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 10000
Awt input thread poll interval: 100000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 112
SIGTERM 1
total: 113

syscall seconds calls errors
pause .01 102 102
ioctl .11 324
poll .01 328
sigprocmask .24 1715
context .17 1254
gettimeofday .14 871
setitimer .00 203
                ---- --- ---
sys totals: .68 4797 102
usr time: .13
elapsed: 10.05
Listening on port 34696
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: default
Awt input thread poll interval: default
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 160
SIGTERM 1
total: 161

syscall seconds calls errors
pause .03 148 148
ioctl .30 532
poll .13 540
sigprocmask .79 2656
context .12 1928
gettimeofday .17 1399
setitimer .09 302
                ---- --- ---
sys totals: 1.63 7505 148
usr time: .36
elapsed: 10.14
[Minimum alarm interval set to 10000 usecs]
[Minimum AWT input thread polling interval set to 10000 usecs]
Listening on port 34692
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 10000
Awt input thread poll interval: 10000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 308
SIGTERM 1
total: 309

syscall seconds calls errors
pause .03 102 102
ioctl .23 1084
poll .16 1086
sigprocmask .81 4973
context .59 3577
gettimeofday .46 2775
setitimer .04 550
                ---- --- ---
sys totals: 2.32 14147 102
usr time: .39
elapsed: 10.05
[Minimum alarm interval set to 10000 usecs]
[Minimum AWT input thread polling interval set to 10000 usecs]
Listening on port 34688
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 10000
Awt input thread poll interval: 10000
SunOS nboc03c 5.4 Generic_101946-35 i86pc i386

*******************************************

signals ------------
SIGALRM 325
SIGTERM 1
total: 326

syscall seconds calls errors
pause .02 102 102
ioctl .36 1136
poll .10 1141
sigprocmask 1.12 5189
context .58 3735
gettimeofday .40 2917
setitimer .03 584
                ---- --- ---
sys totals: 2.61 14804 102
usr time: .53
elapsed: 10.15
[Minimum alarm interval set to 40000 usecs]
[Minimum AWT input thread polling interval set to 200000 usecs]
Listening on port 34738
Waiting on connection...
Starting truss...

*******************************************

Minimum clock resolution: 40000
Awt input thread poll interval