Saturday, January 30, 2010

Linux Java Thread Priorities workaround

First and foremost: This workaround was found by Akshaal, and his blogentry about the problem and the "fix" is here (2008-04-28).

Secondly: Fix/Workaround to let Java on Linux work somewhat with Thread priorities, start the JVM with the following argument:
-XX:ThreadPriorityPolicy=42

For some annoying reason, Sun has decided that to run with threads with working thread priorities on Linux, you have to be root. The logic behind this decision, is that to heighten thread priorities, you have to be root. But, says many of us, could you not just let us lower thread priorities, at least? No, says Sun. I believe they just don't quite understand what is requested.

The sun bug 4813310 tracks this, but it is Closed - Fix Delivered. So the chances of a fix are slim, unless some JDK developer takes mercy.

Anyway - Akshaal found out that if you just set the "ThreadPriorityPolicy" to something else than the legal values 0 or 1, say 2 or 42, or 666 as he suggest himself, a slight logic bug in Sun's JVM code kicks in, and thus sets the policy to be as if running with root - thus you get exactly what one desire. The operating system, Linux, won't allow priorities to be heightened above "Normal" (negative nice value), and thus just ignores those requests (setting it to normal instead, nice value 0) - but it lets through the requests to set it lower (setting the nice value to some positive value).

I wrote a little program to test out priorities and these flags. There are two obvious ways to test such scheduling: Either have a fixed amount of work for each thread at each priority, and time how long time it takes to execute this - or let the system run for a fixed time, and then count how much work is done during this time. I first thought of the latter, so I coded that - and as I think about it further, I realize that this must be the most correct check too: Since if the high priority jobs finish earlier, the timing data of the lower priority jobs will not be entirely correct: There are now, obviously, fewer threads competing for the CPU (of course, one could let each thread do X work, then note how long time that took - and then have the same thread do unlimited amount of work afterward, so that it didn't skew the measurements by exiting before the least priority thread was finished).


Here are the results (2010-01-29 on JDK 1.6.0_18):

As user, with the following arguments (for the rest of the runs, the things changing are user vs. root, and the ThreadPriorityPolicy):

-XX:ThreadPriorityPolicy=0
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintCompilation
  1       java.util.concurrent.atomic.AtomicLong::get (5 bytes)
--- n sun.misc.Unsafe::compareAndSwapLong
--- n sun.misc.Unsafe::compareAndSwapLong
2 java.util.concurrent.atomic.AtomicLong::compareAndSet (13 bytes)
3 java.util.Random::next (47 bytes)
4 java.util.Random::nextDouble (24 bytes)
1% com.example.XThreadPriorities$Runner::run @ 13 (70 bytes)
5 com.example.XThreadPriorities$Runner::run (70 bytes)
Warmup complete.
Running test.
Thread MIN_PRIORITY:[1], NORM_PRIORITY:[5], MAX_PRIORITY:[10].
3924841464 - Pri:1 - 448333661 451444766 472740484 413017157 417892801 548408461 605271612 567732522
3948617160 - Pri:2 - 592733363 404123318 425058572 604107501 519520686 418888175 526486630 457698915
4266211603 - Pri:3 - 761499319 427767980 429864266 603262254 560988584 418244133 641052397 423532670
3646125561 - Pri:4 - 404603024 416434536 429997217 431405433 641421096 478439739 420713663 423110853
3968532194 - Pri:5 - 415064763 422632368 419370153 604712758 561722145 418841260 521415092 604773655
4006791532 - Pri:6 - 420221100 422553508 614947805 561412057 641625815 479341536 432081606 434608105
4014589807 - Pri:7 - 585756485 418316991 520996504 474136186 637166908 419697931 434488836 524029966
4192942528 - Pri:8 - 480067579 472195975 589334074 519719204 640510132 420580090 462976949 607558525
3965592952 - Pri:9 - 419045425 475155351 473396403 540690307 520495432 522822449 598591571 415396014
3603044034 - Pri:10 - 419117989 421450664 520872436 429775340 566700552 418128806 414890139 412108108
TotalyDummy: [0.13069701389705252].
Heap
PSYoungGen total 27904K, used 957K [0x00000000e0e00000, 0x00000000e2d20000, 0x0000000100000000)
eden space 23936K, 4% used [0x00000000e0e00000,0x00000000e0eef640,0x00000000e2560000)
from space 3968K, 0% used [0x00000000e2940000,0x00000000e2940000,0x00000000e2d20000)
to space 3968K, 0% used [0x00000000e2560000,0x00000000e2560000,0x00000000e2940000)
PSOldGen total 63744K, used 0K [0x00000000a2a00000, 0x00000000a6840000, 0x00000000e0e00000)
object space 63744K, 0% used [0x00000000a2a00000,0x00000000a2a00000,0x00000000a6840000)
PSPermGen total 21248K, used 2534K [0x000000009d600000, 0x000000009eac0000, 0x00000000a2a00000)
object space 21248K, 11% used [0x000000009d600000,0x000000009d8799c8,0x000000009eac0000)

As user, with -XX:ThreadPriorityPolicy=1. Notice the warning:

Java HotSpot(TM) 64-Bit Server VM warning: -XX:ThreadPriorityPolicy requires root privilege on Linux
...
4074355867 - Pri:1 - 527880034 510291794 506778321 500873083 507354362 494273347 543124483 483780443
4070970485 - Pri:2 - 502093074 507450387 513538019 548011008 515777472 510318658 492394477 481387390
4166089696 - Pri:3 - 545072864 510212654 503618003 545454609 509985968 499563619 542154550 510027429
3938795103 - Pri:4 - 499309103 482262429 483892136 484047646 493485804 497920357 486252326 511625302
4030810973 - Pri:5 - 492208426 510091021 472609917 551737964 511926521 488736661 495151696 508348767
3991986357 - Pri:6 - 499139701 484193553 508453245 494823573 505428815 491609383 495135614 513202473
3970332529 - Pri:7 - 508806026 484872150 460815795 545766805 487437289 484429061 511512703 486692700
3985129481 - Pri:8 - 508044296 493994479 486757819 504809264 504582073 489230988 485472873 512237689
3993531405 - Pri:9 - 485761906 508066620 498470220 526708671 484472110 474413825 498665020 516973033
3880591568 - Pri:10 - 482605449 492966477 494274413 512614969 525299924 401406096 483149581 488274659


As root, with -XX:ThreadPriorityPolicy=1:
...
1192628609 - Pri:1 - 146366375 145886054 145439504 148594629 154873659 145337314 155007218 151123856
1600638473 - Pri:2 - 293845127 182254047 179729049 186290117 174455802 186991284 194082370 202990677
1865691639 - Pri:3 - 252269194 240399347 219981901 223897910 228422404 242806673 239024804 218889406
2405100112 - Pri:4 - 303976233 283413460 310125261 300915820 286445060 313188957 295836808 311198513
2895152789 - Pri:5 - 355221596 377247451 374614383 338382343 361193338 352556243 376620158 359317277
3575027949 - Pri:6 - 430714357 452538422 438269143 451133734 476982979 437064495 436451954 451872865
4443379518 - Pri:7 - 576373599 575729812 528069437 559187021 582029237 539218400 520491072 562280940
5573457006 - Pri:8 - 684559763 685997740 722733003 672837267 683740096 716802117 697600305 709186715
7105117744 - Pri:9 - 885538364 920253981 855196886 825353759 909130110 960094293 864861817 884688534
9047448786 - Pri:10 - 1102826483 1079059728 1170567845 1062711472 1103250654 1194296507 1152074721 1182661376


As user, with "hack" -XX:ThreadPriorityPolicy=42:
...
1908592461 - Pri:1 - 252347610 268364950 217692707 199375572 241284341 243700244 267888904 217938133
2553635695 - Pri:2 - 345500976 320245701 313000117 330487363 307702106 304209714 312839609 319650109
3061308188 - Pri:3 - 352952639 431153057 415115944 336767623 412447023 393943268 380318370 338610264
4023325349 - Pri:4 - 532822164 500246668 509185449 515950251 422229930 551608063 511732302 479550522
4789209609 - Pri:5 - 625601672 530227747 622740566 599139605 725003140 602205329 596298732 487992818
4730674281 - Pri:6 - 625476539 482470376 726537575 655716492 487662808 621938212 601082560 529789719
4881113871 - Pri:7 - 652977961 586461749 726919389 595618652 484349203 661139324 684148172 489499421
4533403095 - Pri:8 - 614634085 484084154 526523754 643123946 599005063 647009071 532566904 486456118
4727219915 - Pri:9 - 625026801 596318117 726547378 598978337 601971731 489284222 491219584 597873745
4827951033 - Pri:10 - 678619163 525617294 592417838 657638409 722179525 484460205 531506557 635512042



As user, with "hack" and specific setting of OS priorities. We start at Unix nice level 0 for the highest java priority, going down to 9 for the lowest java priority. Notice how this leads to the situation where a NORMAL priority java thread have a quite significant nice level (low priority) on the OS side. Thus, in a contended environment with other processes running on the machine competing for CPU resources, "normal" java threads will loose out to the other processes, so this is not a complete solution:

-XX:ThreadPriorityPolicy=42
-XX:JavaPriority10_To_OSPriority=0
-XX:JavaPriority9_To_OSPriority=1
-XX:JavaPriority8_To_OSPriority=2
-XX:JavaPriority7_To_OSPriority=3
-XX:JavaPriority6_To_OSPriority=4
-XX:JavaPriority5_To_OSPriority=5
-XX:JavaPriority4_To_OSPriority=6
-XX:JavaPriority3_To_OSPriority=7
-XX:JavaPriority2_To_OSPriority=8
-XX:JavaPriority1_To_OSPriority=9
...
1181594447 - Pri:1 - 156646712 163727007 149271484 148003186 146046042 142171936 136636764 139091316
1467758385 - Pri:2 - 181741621 207823162 180440610 178282147 181600823 175446181 174811880 187611961
1835430827 - Pri:3 - 249361299 241085322 198475979 220310800 212862944 227538859 223721751 262073873
2310513758 - Pri:4 - 298831212 311762873 263149604 261915158 279594960 280329975 284289057 330640919
2820606635 - Pri:5 - 417528424 337381991 374884808 300077072 359420239 346286405 382398636 302629060
3517176583 - Pri:6 - 450919929 431990553 434093985 473421346 471673385 375806611 457967591 421303183
4386636298 - Pri:7 - 526555707 475575838 600301353 603713184 570267602 475066321 489751343 645404950
5646571395 - Pri:8 - 897622033 693133727 703208339 759090217 712003197 591393673 618879272 671240937
6260518137 - Pri:9 - 797127673 797467534 739969033 913730558 735004475 798095374 736360300 742763190
10144752105 - Pri:10 - 1504673551 1155125325 1123163868 1302155597 1390019512 1216611268 1208440124 1244562860

To directly see the problem where normal threads, which have java priority 5, gets unfair treatment with the above solution, I ran a quick test with two such tests simultaneously using the following little shell script (I also didn't run for 5 minutes here):
$ cat test.sh 
#!/bin/sh

java \
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintCompilation -classpath eclipsebuild com.example.XThreadPriorities &

java \
-XX:ThreadPriorityPolicy=42 \
-XX:JavaPriority10_To_OSPriority=0 \
-XX:JavaPriority9_To_OSPriority=1 \
-XX:JavaPriority8_To_OSPriority=2 \
-XX:JavaPriority7_To_OSPriority=3 \
-XX:JavaPriority6_To_OSPriority=4 \
-XX:JavaPriority5_To_OSPriority=5 \
-XX:JavaPriority4_To_OSPriority=6 \
-XX:JavaPriority3_To_OSPriority=7 \
-XX:JavaPriority2_To_OSPriority=8 \
-XX:JavaPriority1_To_OSPriority=9 \
-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintCompilation -classpath eclipsebuild com.example.XThreadPriorities &

This lead to the following result:
70479632 - Pri:1 -  15781306 7639485 8364936 7772256 7424872 7930535 7750748 7815494
80416568 - Pri:2 - 11971141 9843537 9242104 9872974 10394428 9485233 9989330 9617821
103451737 - Pri:3 - 15886246 12949826 11725092 13793650 12614427 11656444 12344883 12481169
143220837 - Pri:4 - 32940102 16299182 14991785 16375282 15634409 14790916 15922255 16266906
159230735 - Pri:5 - 20471865 19681922 18727162 25211867 17791552 18787357 19537079 19021931
199052863 - Pri:6 - 24375945 25213341 24205803 31016513 22616403 23760056 23570549 24294253
245144874 - Pri:7 - 32218827 32270732 30006087 31789704 27064661 32474676 30256065 29064122
318656402 - Pri:8 - 38021055 39259080 44766347 49071457 34923402 35975708 40544736 36094617
401223243 - Pri:9 - 48600625 49467360 60141538 49625176 43789040 56507123 48418800 44673581
483842551 - Pri:10 - 58150216 58609942 77028357 59819032 53866188 59828368 59407580 57132868
TotalWork: [2204719442] (TotalyDummy: [29.703316307452084]).

469978381 - Pri:1 - 78278984 54629208 68421300 50861462 59341367 47883726 52597471 57964863
446759823 - Pri:2 - 77297533 50977670 73351930 50608554 47847622 46878431 53587386 46210697
472936111 - Pri:3 - 59336726 53398323 72483088 72872361 62524544 50161550 54083565 48075954
460567710 - Pri:4 - 59351070 51692155 72606512 72652587 47014898 52273533 46462284 58514671
467930078 - Pri:5 - 58932415 51900432 71509566 73609344 59049535 51626557 46980275 54321954
416276726 - Pri:6 - 58922845 55446857 47075994 47381016 47463150 52581761 52572845 54832258
461001441 - Pri:7 - 69723843 59707979 47522091 53322726 47818110 67710544 60742003 54454145
455315271 - Pri:8 - 49172227 61493744 62323717 50959541 47825115 70684358 51816372 61040197
424012117 - Pri:9 - 49651798 56514868 46221793 54045253 53094738 52019573 55008343 57455751
428007514 - Pri:10 - 48523372 47959147 49071583 62248855 51265246 51405853 54465519 63067939
TotalWork: [4502785172] (TotalyDummy: [-14.989963287910708]).


The best solution for running as user is probably the "-XX:ThreadPriorityPolicy=42" without the specific setting of OS levels. In that scenario, a normal priority java thread gets a normal OS nice level, while it still is possible to let e.g. "batch processing threads" get a lower nice level. The only thing that I'd appreciate was if the (AWT) Event Dispatch Thread got a notch higher priority than all other threads. Java does exactly that, by setting the EDT's priority to 6 (but as shown, that doesn't matter here, all priorities higher than 5 gets effectively 5 anyway). However, by setting all other threads in a GUI application down a notch (to 4 or less), you'd get the same effect.

Just to point it out: The above solution should be the default. This gives at least a somewhat reasonable logic: You can lower the priority, but you cannot jack it above normal. What one really would want, is that these priorities only worked within the process, not globally across the system. Then one could jack some threads "above normal", as they would only affect the scheduling within this process' threads. But this would apparently require a change in Linux.

Here's the code. It should be possible to just copy-paste it onto a project node of a Eclipse project (stand on the project node, hit Ctrl-V), thus getting it runnable instantly:

package com.example;

import java.util.Random;

/**
* Tests the Thread priorities of a Java program by letting threads run "unlimited amounts" of work for a fixed period
* of time, counting how much work they get done.
*
* @author Endre Stølsvik
*/
public class XThreadPriorities {

static volatile boolean _runThreads;

public static final int PARALLELS = Runtime.getRuntime().availableProcessors();

public static final int RUNNING_WARMUP_SECONDS = 4;

public static final int RUNNING_SECONDS = 60 * 5;

public static void main(String[] args) throws InterruptedException {
// Run warmup
run(RUNNING_WARMUP_SECONDS);
System.out.println("Warmup complete.");
Thread.sleep(500);
System.out.println("Running test.");
// Run test
Runner[][] runners = run(RUNNING_SECONDS);

// Dump results.
System.out.println("Thread MIN_PRIORITY:[" + Thread.MIN_PRIORITY + "], NORM_PRIORITY:[" + Thread.NORM_PRIORITY
+ "], MAX_PRIORITY:[" + Thread.MAX_PRIORITY + "].");

double totalDummy = 0;
long totalWork = 0;
for (int j = 0; j < runners[0].length; j++) {
int pri = runners[0][j]._priority;
String msg = "Pri:" + pri + " - ";
long total = 0;
for (int i = 0; i < runners.length; i++) {
totalDummy = runners[i][j]._dummy;
assert pri == runners[i][j]._priority;
long counter = runners[i][j]._counter;
total += counter;
msg += " " + counter;
}
totalWork += total;
System.out.println(total + " - " + msg);
}
System.out.println("TotalWork: [" + totalWork + "] (TotalyDummy: [" + totalDummy + "]).");
}

private static Runner[][] run(int seconds) throws InterruptedException {
_runThreads = true;
int priorities = Thread.MAX_PRIORITY - Thread.MIN_PRIORITY + 1;
Runner[][] runners = new Runner[PARALLELS][priorities];
// Make threads
for (int i = 0; i < PARALLELS; i++) {
int pri = Thread.MIN_PRIORITY;
for (int j = 0; j < priorities; j++) {
runners[i][j] = new Runner(pri++);
}
}
// Start threads.
for (int i = 0; i < PARALLELS; i++) {
for (int j = 0; j < priorities; j++) {
runners[i][j].start();
}
}
// Run all threads for whatever number of seconds.
Thread.sleep(seconds * 1000);
// Ask threads to stop.
_runThreads = false;
// Make sure they're stopped by joining them
for (int i = 0; i < PARALLELS; i++) {
for (int j = 0; j < priorities; j++) {
runners[i][j].join();
}
}
return runners;
}

private static class Runner extends Thread {
final Random _random = new Random();
final int _priority;

public Runner(int priority) {
this._priority = priority;
}

long _counter = 0;
double _dummy = 0;

@Override
public void run() {
Thread.currentThread().setPriority(_priority);
while (_runThreads) {
_counter++;
_dummy += (_random.nextDouble() * 2 - 1) / 123.579 * (_random.nextDouble() * 2 - 1);
}
}
}
}


6 comments:

  1. Excellent write up, thank-you for the code too.

    ReplyDelete
  2. Wow Thanks So much! This really helped!

    ReplyDelete
  3. Does not seem to be working on hotspot 1.6.0_27. I'm using -XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=2. I get no warning and the thread dump says all threads are priority 10. This is on CentOS (variant of linux used for webservers and clusters). Would be great if you could confirm!
    Anyway, relying on an un-fixed bug is asking for trouble. Many thanks for this post!

    ReplyDelete
  4. Is it possible to create a thread in Java with the highest priority in the OS or at least high enough so that it is never preempted by other Java threads or OS threads?

    ReplyDelete
  5. @Rebecca: Yes, I believe so. On linux, you need to be root. On windows, you should be able right away, unless a SecurityManager sits in your way.

    ReplyDelete